* released 1.1.25
* added the 'tcplog' option, which provides enhanced, HTTP-like logs for generic TCP proxies, or lighter logs for HTTP proxies. * fixed a time-out condition wrongly reported as client time-out in data phase if the client timeout was lower than the connect timeout times the number of retries. * doc: added some precisions about the log timers
This commit is contained in:
parent
197e8ec2c3
commit
c1cae63922
@ -1,6 +1,13 @@
|
||||
ChangeLog :
|
||||
===========
|
||||
|
||||
2003/10/15 : 1.1.25
|
||||
- added the 'tcplog' option, which provides enhanced, HTTP-like logs for
|
||||
generic TCP proxies, or lighter logs for HTTP proxies.
|
||||
- fixed a time-out condition wrongly reported as client time-out in data
|
||||
phase if the client timeout was lower than the connect timeout times the
|
||||
number of retries.
|
||||
|
||||
2003/09/21 : 1.1.24
|
||||
- if a client sent a full request then shut its write connection down, then
|
||||
the request was aborted. This case was detected only when using haproxy
|
||||
|
@ -1,9 +1,9 @@
|
||||
|
||||
H A - P r o x y
|
||||
---------------
|
||||
version 1.1.24
|
||||
version 1.1.25
|
||||
willy tarreau
|
||||
2003/09/21
|
||||
2003/10/15
|
||||
|
||||
============
|
||||
| Abstract |
|
||||
@ -857,7 +857,8 @@ Example :
|
||||
|
||||
4.2) Event logging
|
||||
------------------
|
||||
|
||||
4.2.1) Log levels
|
||||
-----------------
|
||||
TCP and HTTP connections can be logged with informations such as date, time,
|
||||
source IP address, destination address, connection duration, response times,
|
||||
HTTP request, the HTTP return code, number of bytes transmitted, the conditions
|
||||
@ -883,12 +884,20 @@ Example :
|
||||
log 192.168.2.200 local3
|
||||
log 192.168.2.201 local4
|
||||
|
||||
By default, only TCP information is logged. It is necessary to set the 'httplog'
|
||||
option to obtain more detailed information about HTTP contents. In the event
|
||||
where an external component would establish frequent connections to check the
|
||||
service, logs may be full of useless lines. So it is possible not to log any
|
||||
session which didn't transfer any data, by the setting of the 'dontlognull'
|
||||
option. This only has effect on sessions which are established then closed.
|
||||
4.2.2) Log format
|
||||
-----------------
|
||||
By default, connections are logged at the TCP level, as soon as the session
|
||||
establishes between the client and the proxy. By enabling the 'tcplog' option,
|
||||
the proxy will wait until the session ends to generate an enhanced log
|
||||
containing more information such as session duration and its state during the
|
||||
disconnection.
|
||||
|
||||
Another option, 'httplog', provides more detailed information about HTTP
|
||||
contents, such as the request and some cookies. In the event where an external
|
||||
component would establish frequent connections to check the service, logs may be
|
||||
full of useless lines. So it is possible not to log any session which didn't
|
||||
transfer any data, by the setting of the 'dontlognull' option. This only has
|
||||
effect on sessions which are established then closed.
|
||||
|
||||
Example :
|
||||
---------
|
||||
@ -898,8 +907,73 @@ Example :
|
||||
option dontlognull
|
||||
log 192.168.2.200 local3
|
||||
|
||||
Since version 1.1.18, a session completion indicator has been added to HTTP
|
||||
logs. It's a 4-characters field preceeding the HTTP request, and indicating :
|
||||
4.2.3) Timing events
|
||||
--------------------
|
||||
Timers provide a great help in trouble shooting network problems. All values
|
||||
are reported in milliseconds (ms). In HTTP mode, four control points are
|
||||
reported under the form 'Tq/Tc/Tr/Tt' :
|
||||
|
||||
- Tq: total time to get the client request.
|
||||
It's the time elapsed between the moment the client connection was accepted
|
||||
and the moment the proxy received the last HTTP header. The value '-1'
|
||||
indicates that the end of headers (empty line) has never been seen.
|
||||
|
||||
- Tc: total time to establish the TCP connection to the server.
|
||||
It's the time elapsed between the moment the proxy sent the connection
|
||||
request, and the moment it was acknowledged, or between the TCP SYN packet
|
||||
and the matching SYN/ACK in return. The value '-1' means that the
|
||||
connection never established.
|
||||
|
||||
- Tr: server response time. It's the time elapsed between the moment the
|
||||
TCP connection was established to the server and the moment it send its
|
||||
complete response header. It purely shows its request processing time,
|
||||
without the network overhead due to the data transmission. The value '-1'
|
||||
means that the last the response header (empty line) was never seen.
|
||||
|
||||
- Tt: total session duration time, between the moment the proxy accepted it
|
||||
and the moment both ends were closed. From this one, we can deduce Td,
|
||||
the data transmission time, by substracting other timers when valid :
|
||||
|
||||
Td = Tt - (Tq + Tc + Tr)
|
||||
|
||||
Timers with '-1' values have to be excluded from this equation.
|
||||
|
||||
In TCP mode ('option tcplog'), only Tc and Tt are reported.
|
||||
|
||||
These timers provide precious indications on trouble causes. Since the TCP
|
||||
protocol defines retransmit delays of 3, 6, 12... seconds, we know for sure
|
||||
that timers close to multiples of 3s are nearly always related to packets lost
|
||||
due to network problems (wires or negociation). Moreover, if <Tt> is close to
|
||||
a timeout value specified in the configuration, it often means that a session
|
||||
has been aborted on time-out.
|
||||
|
||||
Most common cases :
|
||||
|
||||
- If Tq is close to 3000, a packet has probably been lost between the client
|
||||
and the proxy.
|
||||
- If Tc is close to 3000, a packet has probably been lost between the server
|
||||
and the proxy during the server connection phase. This one should always be
|
||||
very low (less than a few tens).
|
||||
- If Tr is nearly always lower than 3000 except some rare values which seem to
|
||||
be the average majored by 3000, there are probably some packets lost between
|
||||
the proxy and the server.
|
||||
- If Tt is often slightly higher than a time-out, it's often because the
|
||||
client and the server use HTTP keep-alive and the session is maintained
|
||||
after the response ends. Se further for how to disable HTTP keep-alive.
|
||||
|
||||
Other cases ('xx' means any value to be ignored) :
|
||||
-1/xx/xx/Tt : the client was not able to send its complete request in time,
|
||||
or that it aborted it too early.
|
||||
Tq/-1/xx/Tt : the connection could not establish on the server. Either it
|
||||
refused it or it timed out after Tt-Tq ms.
|
||||
Tq/Tc/-1/Tt : the server has accepted the connection but did not return a
|
||||
complete response in time, or it closed its connexion
|
||||
unexpectedly, after Tt-(Tq+Tc) ms.
|
||||
|
||||
4.2.4) Session state at disconnection
|
||||
-------------------------------------
|
||||
TCP and HTTP logs provide a session completion indicator. It's a 4-characters
|
||||
(2 in TCP) field preceeding the HTTP request, and indicating :
|
||||
- On the first character, a code reporting the first event which caused the
|
||||
session to terminate :
|
||||
|
||||
@ -922,7 +996,7 @@ logs. It's a 4-characters field preceeding the HTTP request, and indicating :
|
||||
- : normal session completion after end of data transfer.
|
||||
|
||||
- the third character tells whether the persistence cookie was provided by
|
||||
the client :
|
||||
the client (only in HTTP mode) :
|
||||
|
||||
N : the client provided NO cookie.
|
||||
I : the client provided an INVALID cookie matching no known server.
|
||||
@ -935,7 +1009,7 @@ logs. It's a 4-characters field preceeding the HTTP request, and indicating :
|
||||
- : does not apply (no cookie set in configuration).
|
||||
|
||||
- the last character reports what operations were performed on the persistence
|
||||
cookie returned by the server :
|
||||
cookie returned by the server (only in HTTP mode) :
|
||||
|
||||
N : NO cookie was provided by the server.
|
||||
P : a cookie was PROVIDED by the server and transmitted as-is.
|
||||
@ -968,20 +1042,30 @@ In the logs, the field preceeding the completion indicator contains the cookie
|
||||
value as sent by the server, preceeded by the cookie value as sent by the
|
||||
client. Each of these field is replaced with '-' when no cookie was seen.
|
||||
|
||||
Last, the 'forwardfor' option creates an HTTP 'X-Forwarded-For' header which
|
||||
contains the client's IP address. This is useful to let the final web server
|
||||
know what the client address was (eg for statistics on domains).
|
||||
4.2.5) Examples of logs
|
||||
-----------------------
|
||||
- haproxy[674]: 127.0.0.1:33319 [15/Oct/2003:08:31:57] relais-http Srv1 6559/7/147/6723 200 243 - - ---- "HEAD / HTTP/1.0"
|
||||
=> long request (6.5s) entered by hand through 'telnet'. The server replied
|
||||
in 147 ms, and the session ended normally ('----')
|
||||
|
||||
Example :
|
||||
---------
|
||||
listen http_proxy 0.0.0.0:80
|
||||
mode http
|
||||
log global
|
||||
option httplog
|
||||
option dontlognull
|
||||
option forwardfor
|
||||
capture cookie userid= len 20
|
||||
- haproxy[18113]: 127.0.0.1:34548 [15/Oct/2003:15:18:55] relais-http <NOSRV> -1/-1/-1/8490 -1 0 - - CR-- ""
|
||||
=> the client never completed its request and aborted itself ('C---') after
|
||||
8.5s, while the proxy was waiting for the request headers ('-R--').
|
||||
Nothing was sent to the server.
|
||||
|
||||
- haproxy[18113]: 127.0.0.1:34549 [15/Oct/2003:15:19:06] relais-http <NOSRV> -1/-1/-1/50001 408 0 - - cR-- ""
|
||||
=> The client never completed its request, which was aborted by the time-out
|
||||
('c---') after 50s, while the proxy was waiting for the request headers ('-R--').
|
||||
Nothing was sent to the server, but the proxy could send a 408 return code
|
||||
to the client.
|
||||
|
||||
- haproxy[18989]: 127.0.0.1:34550 [15/Oct/2003:15:24:28] relais-tcp Srv1 0/5007 0 cD
|
||||
=> This is a 'tcplog' entry. Client-side time-out ('c----') occured after 5s.
|
||||
|
||||
- haproxy[18989]: 10.0.0.1:34552 [15/Oct/2003:15:26:31] relais-http Srv1 3183/-1/-1/11215 503 0 - - SC-- "HEAD / HTTP/1.0"
|
||||
=> The request took 3s to complete (probably a network problem), and the
|
||||
connection to the server failed ('SC--') after 4 attemps of 2 seconds
|
||||
(config says 'retries 3'), then a 503 error code was sent to the client.
|
||||
|
||||
4.3) HTTP header manipulation
|
||||
-----------------------------
|
||||
@ -1096,7 +1180,18 @@ Examples :
|
||||
rspadd Server:\ Formilux/0.1.8
|
||||
|
||||
|
||||
- 8< - - - 8< - - - 8< - - - 8< - - - 8< - - - 8< - - -
|
||||
Last, the 'forwardfor' option creates an HTTP 'X-Forwarded-For' header which
|
||||
contains the client's IP address. This is useful to let the final web server
|
||||
know what the client address was (eg for statistics on domains).
|
||||
|
||||
Example :
|
||||
---------
|
||||
listen http_proxy 0.0.0.0:80
|
||||
mode http
|
||||
log global
|
||||
option httplog
|
||||
option dontlognull
|
||||
option forwardfor
|
||||
|
||||
4.4) Load balancing with persistence
|
||||
------------------------------------
|
||||
|
@ -1,9 +1,9 @@
|
||||
|
||||
H A - P r o x y
|
||||
---------------
|
||||
version 1.1.24
|
||||
version 1.1.25
|
||||
willy tarreau
|
||||
2003/09/21
|
||||
2003/10/15
|
||||
|
||||
================
|
||||
| Introduction |
|
||||
@ -875,6 +875,8 @@ Exemple :
|
||||
|
||||
4.2) Journalisation des connexions
|
||||
----------------------------------
|
||||
4.2.1) Niveaux de log
|
||||
---------------------
|
||||
Les connexions TCP et HTTP peuvent donner lieu à une journalisation sommaire ou
|
||||
détaillée indiquant, pour chaque connexion, la date, l'heure, l'adresse IP
|
||||
source, le serveur destination, la durée de la connexion, les temps de réponse,
|
||||
@ -901,12 +903,20 @@ Exemple :
|
||||
log 192.168.2.200 local3
|
||||
log 192.168.2.201 local4
|
||||
|
||||
Par défaut, les informations contenues dans les logs se situent au niveau TCP
|
||||
uniquement. Il faut préciser l'option 'httplog' pour obtenir les détails du
|
||||
protocole HTTP. Dans les cas où un mécanisme de surveillance effectuant des
|
||||
connexions et déconnexions fréquentes, polluerait les logs, il suffit d'ajouter
|
||||
l'option 'dontlognull', pour ne plus obtenir une ligne de log pour les sessions
|
||||
n'ayant pas donné lieu à un échange de données (requête ou réponse).
|
||||
4.2.2) Format des logs
|
||||
----------------------
|
||||
Par défaut, les connexions sont journalisées au niveau TCP dès l'établissement
|
||||
de la session entre le client et le relais. En précisant l'option 'tcplog',
|
||||
la connexion ne sera journalisée qu'en fin de session, ajoutant des précisions
|
||||
sur son état lors de la déconnexion, ainsi que le temps de connexion et la
|
||||
durée totale de la session.
|
||||
|
||||
Une autre option, 'httplog', fournit plus de détails sur le protocole HTTP,
|
||||
notamment la requête et l'état des cookies. Dans les cas où un mécanisme de
|
||||
surveillance effectuant des connexions et déconnexions fréquentes, polluerait
|
||||
les logs, il suffit d'ajouter l'option 'dontlognull', pour ne plus obtenir une
|
||||
ligne de log pour les sessions n'ayant pas donné lieu à un échange de données
|
||||
(requête ou réponse).
|
||||
|
||||
Exemple :
|
||||
---------
|
||||
@ -916,9 +926,80 @@ Exemple :
|
||||
option dontlognull
|
||||
log 192.168.2.200 local3
|
||||
|
||||
Depuis la version 1.1.18, un indicateur de complétude de la session a été ajouté
|
||||
dans les logs HTTP. C'est un champ de 4 caractères précédant la requête HTTP,
|
||||
indiquant :
|
||||
4.2.3) Chronométrage des événements
|
||||
-----------------------------------
|
||||
Pour déceler des problèmes réseau, les mesures du temps écoulé entre certains
|
||||
événements sont d'une très grande utilité. Tous les temps sont mesurés en
|
||||
millisecondes (ms). En mode HTTP, quatre points de mesure sont rapportés sous
|
||||
la forme Tq/Tc/Tr/Tt :
|
||||
|
||||
- Tq: temps total de réception de la requête HTTP de la part du client.
|
||||
C'est le temps qui s'est écoulé entre le moment où le client a établi
|
||||
sa connexion vers le relais, et le moment où ce dernier a reçu le dernier
|
||||
en-tête HTTP validant la fin de la requête. Une valeur '-1' ici indique
|
||||
que la requête complète n'a jamais été reçue.
|
||||
|
||||
- Tc: temps d'établissement de la connexion TCP du relais vers le serveur.
|
||||
C'est le temps écoulé entre le moment ou le relais a initié la demande de
|
||||
connexion vers le serveur, et le moment où ce dernier l'a acquittée, c'est
|
||||
à dire le temps entre l'envoi du paquet TCP SYN la réception du SYN/ACK.
|
||||
Une valeur '-1' ici indique que la connexion n'a jamais pu être établie
|
||||
vers le serveur.
|
||||
|
||||
- Tr: temps de réponse du serveur. C'est le temps que le serveur a mis pour
|
||||
renvoyer la totalité des entêtes HTTP à partir du moment où il a acquitté
|
||||
la connexion. Ca représente exactement le temps de traitement de la
|
||||
transaction sans le transfert des données associées. Une valeur '-1'
|
||||
indique que le serveur n'a pas envoyé la totalité de l'entête HTTP.
|
||||
|
||||
- Tt: durée de vie totale de la session, entre le moment où la demande de
|
||||
connexion du client a été acquittée et le moment où la connexion a été
|
||||
refermée aux deux extrémités (client et serveur). On peut donc en déduire
|
||||
Td, le temps de transfert des données, en excluant les autres temps :
|
||||
|
||||
Td = Tt - (Tq + Tc + Tr)
|
||||
|
||||
Les temps rapportés à '-1' sont simplement à éliminer de cette équation.
|
||||
|
||||
En mode TCP ('option tcplog'), seuls les deux indicateurs Tc et Tt sont
|
||||
rapportés.
|
||||
|
||||
Ces temps fournissent de précieux renseignement sur des causes probables de
|
||||
problèmes. Du fait que le protocole TCP définisse des temps de retransmission
|
||||
de 3 secondes, puis 6, 12, etc..., l'observation de temps proches de multiples
|
||||
de 3 secondes indique pratiquement toujours des pertes de paquets liés à un
|
||||
problème réseau (câble ou négociation). De plus, si <Tt> est proche d'une
|
||||
valeur de time-out dans la configuration, c'est souvent qu'une session a été
|
||||
abandonnée sur expiration d'un time-out.
|
||||
|
||||
Cas les plus fréquents :
|
||||
|
||||
- Si Tq est proche de 3000, un paquet a très certainement été perdu entre
|
||||
le client et le relais.
|
||||
- Si Tc est proche de 3000, un paquet a très certainement été perdu entre
|
||||
le relais et le serveur durant la phase de connexion. Cet indicateur
|
||||
devrait normalement toujours être très bas (moins de quelques dizaines).
|
||||
- Si Tr est presque toujours inférieur à 3000, et que certaines valeurs
|
||||
semblent proches de la valeur moyenne majorée de 3000, il y a peut-être
|
||||
de pertes entre le relais et le serveur.
|
||||
- Si Tt est légèrement supérieur au time-out, c'est souvent parce que le
|
||||
client et le serveur utilisent du keep-alive HTTP entre eux et que la
|
||||
session est maintenue après la fin des échanges. Voir plus loin pour
|
||||
savoir comment désactiver le keep-alive HTTP.
|
||||
|
||||
Autres cas ('xx' représentant une valeur quelconque à ignorer) :
|
||||
-1/xx/xx/Tt : le client n'a pas envoyé sa requête dans le temps imparti ou
|
||||
a refermé sa connexion sans compléter la requête.
|
||||
Tq/-1/xx/Tt : la connexion n'a pas pu s'établir vers le serveur (refus ou
|
||||
time-out au bout de Tt-Tq ms).
|
||||
Tq/Tc/-1/Tt : le serveur a accepté la connexion mais n'a pas répondu dans
|
||||
les temps ou bien a refermé sa connexion trop tôt, au bout
|
||||
de Tt-(Tq+Tc) ms.
|
||||
|
||||
4.2.4) Conditions de déconnexion
|
||||
--------------------------------
|
||||
Les logs TCP et HTTP fournissent un indicateur de complétude de la session.
|
||||
C'est un champ de 4 caractères (2 en TCP) précédant la requête HTTP, indiquant :
|
||||
- sur le premier caractère, un code précisant le premier événement qui a causé
|
||||
la terminaison de la session :
|
||||
|
||||
@ -942,7 +1023,7 @@ indiquant :
|
||||
- : terminaison normale, après fin de transfert des données
|
||||
|
||||
- le troisième caractère indique l'éventuelle identification d'un cookie de
|
||||
persistence :
|
||||
persistence (uniquement en mode HTTP) :
|
||||
|
||||
N : aucun cookie de persistence n'a été présenté.
|
||||
I : le client a présenté un cookie ne correspondant à aucun serveur
|
||||
@ -956,7 +1037,7 @@ indiquant :
|
||||
- : non appliquable
|
||||
|
||||
- le dernier caractère indique l'éventuel traitement effectué sur un cookie de
|
||||
persistence retrourné par le serveur :
|
||||
persistence retrourné par le serveur (uniquement en mode HTTP) :
|
||||
|
||||
N : aucun cookie de persistence n'a été fourni par le serveur.
|
||||
P : un cookie de persistence a été fourni par le serveur et transmis
|
||||
@ -994,20 +1075,31 @@ positionn
|
||||
ces champs est remplacé par le signe "-" lorsqu'aucun cookie n'est fourni par le
|
||||
client ou le serveur.
|
||||
|
||||
Enfin, l'option 'forwardfor' ajoute l'adresse IP du client dans un champ
|
||||
'X-Forwarded-For' de la requête, ce qui permet à un serveur web final de
|
||||
connaître l'adresse IP du client initial.
|
||||
4.2.5) Exemples de logs
|
||||
-----------------------
|
||||
- haproxy[674]: 127.0.0.1:33319 [15/Oct/2003:08:31:57] relais-http Srv1 6559/7/147/6723 200 243 - - ---- "HEAD / HTTP/1.0"
|
||||
=> requête longue (6.5s) saisie à la main avec un client telnet. Le serveur a
|
||||
répondu en 147 ms et la session s'est terminée normalement ('----')
|
||||
|
||||
Exemple :
|
||||
---------
|
||||
listen http_proxy 0.0.0.0:80
|
||||
mode http
|
||||
log global
|
||||
option httplog
|
||||
option dontlognull
|
||||
option forwardfor
|
||||
capture cookie userid= len 20
|
||||
- haproxy[18113]: 127.0.0.1:34548 [15/Oct/2003:15:18:55] relais-http <NOSRV> -1/-1/-1/8490 -1 0 - - CR-- ""
|
||||
=> Le client n'a pas envoyé sa requête et a refermé la connexion lui-même
|
||||
('C---') au bout de 8.5s, alors que le relais attendait l'entête ('-R--').
|
||||
Aucune connexion n'a été envoyée vers le serveur.
|
||||
|
||||
- haproxy[18113]: 127.0.0.1:34549 [15/Oct/2003:15:19:06] relais-http <NOSRV> -1/-1/-1/50001 408 0 - - cR-- ""
|
||||
=> Le client n'a pas envoyé sa requête et son time-out a expiré ('c---') au
|
||||
bout de 50s, alors que le relais attendait l'entête ('-R--'). Aucune
|
||||
connexion n'a été envoyée vers le serveur, mais le relais a tout de même
|
||||
pu renvoyer un message 408 au client.
|
||||
|
||||
- haproxy[18989]: 127.0.0.1:34550 [15/Oct/2003:15:24:28] relais-tcp Srv1 0/5007 0 cD
|
||||
=> log en mode 'tcplog'. Expiration du time-out côté client ('c----') au bout
|
||||
de 5s.
|
||||
|
||||
- haproxy[18989]: 10.0.0.1:34552 [15/Oct/2003:15:26:31] relais-http Srv1 3183/-1/-1/11215 503 0 - - SC-- "HEAD / HTTP/1.0"
|
||||
=> La requête client met 3s à entrer (peut-être un problème réseau), et la
|
||||
connexion ('SC--') vers le serveur échoue au bout de 4 tentatives de 2
|
||||
secondes (retries 3 dans la conf), puis un code 503 est retourné au client.
|
||||
|
||||
4.3) Modification des entêtes HTTP
|
||||
----------------------------------
|
||||
@ -1122,6 +1214,19 @@ Exemples :
|
||||
rspadd Server:\ Formilux/0.1.8
|
||||
|
||||
|
||||
Enfin, l'option 'forwardfor' ajoute l'adresse IP du client dans un champ
|
||||
'X-Forwarded-For' de la requête, ce qui permet à un serveur web final de
|
||||
connaître l'adresse IP du client initial.
|
||||
|
||||
Exemple :
|
||||
---------
|
||||
listen http_proxy 0.0.0.0:80
|
||||
mode http
|
||||
log global
|
||||
option httplog
|
||||
option dontlognull
|
||||
option forwardfor
|
||||
|
||||
4.4) Répartition avec persistence
|
||||
---------------------------------
|
||||
|
||||
|
55
haproxy.c
55
haproxy.c
@ -53,8 +53,8 @@
|
||||
#include <linux/netfilter_ipv4.h>
|
||||
#endif
|
||||
|
||||
#define HAPROXY_VERSION "1.1.24"
|
||||
#define HAPROXY_DATE "2003/09/21"
|
||||
#define HAPROXY_VERSION "1.1.25"
|
||||
#define HAPROXY_DATE "2003/10/15"
|
||||
|
||||
/* this is for libc5 for example */
|
||||
#ifndef TCP_NODELAY
|
||||
@ -664,7 +664,7 @@ int process_session(struct task *t);
|
||||
|
||||
void display_version() {
|
||||
printf("HA-Proxy version " HAPROXY_VERSION " " HAPROXY_DATE"\n");
|
||||
printf("Copyright 2000-2002 Willy Tarreau <willy AT meta-x DOT org>\n\n");
|
||||
printf("Copyright 2000-2003 Willy Tarreau <willy AT meta-x DOT org>\n\n");
|
||||
}
|
||||
|
||||
/*
|
||||
@ -1947,6 +1947,7 @@ void sess_log(struct session *s) {
|
||||
char *uri;
|
||||
char *pxid;
|
||||
char *srv;
|
||||
struct tm *tm;
|
||||
|
||||
/* This is a first attempt at a better logging system.
|
||||
* For now, we rely on send_log() to provide the date, although it obviously
|
||||
@ -1960,14 +1961,12 @@ void sess_log(struct session *s) {
|
||||
(unsigned char *)&s->cli_addr.sin_addr :
|
||||
(unsigned char *)"\0\0\0\0";
|
||||
|
||||
uri = (log & LW_REQ) ? s->logs.uri : "<BADREQ>";
|
||||
uri = (log & LW_REQ) ? s->logs.uri ? s->logs.uri : "<BADREQ>" : "";
|
||||
pxid = p->id;
|
||||
//srv = (log & LW_SVID) ? s->srv->id : "<svid>";
|
||||
srv = ((p->to_log & LW_SVID) && s->srv != NULL) ? s->srv->id : "<NOSRV>";
|
||||
|
||||
if (p->to_log & LW_DATE) {
|
||||
struct tm *tm = localtime(&s->logs.tv_accept.tv_sec);
|
||||
srv = (p->to_log & LW_SVID) ? (s->srv != NULL) ? s->srv->id : "<NOSRV>" : "-";
|
||||
|
||||
tm = localtime(&s->logs.tv_accept.tv_sec);
|
||||
if (p->to_log & LW_REQ) {
|
||||
send_log(p, LOG_INFO, "%d.%d.%d.%d:%d [%02d/%s/%04d:%02d:%02d:%02d] %s %s %d/%d/%d/%d %d %lld %s %s %c%c%c%c \"%s\"\n",
|
||||
pn[0], pn[1], pn[2], pn[3], ntohs(s->cli_addr.sin_port),
|
||||
tm->tm_mday, monthname[tm->tm_mon], tm->tm_year+1900,
|
||||
@ -1987,21 +1986,16 @@ void sess_log(struct session *s) {
|
||||
uri);
|
||||
}
|
||||
else {
|
||||
send_log(p, LOG_INFO, "%d.%d.%d.%d:%d %s %s %d/%d/%d/%d %d %lld %s %s %c%c%c%c \"%s\"\n",
|
||||
send_log(p, LOG_INFO, "%d.%d.%d.%d:%d [%02d/%s/%04d:%02d:%02d:%02d] %s %s %d/%d %lld %c%c\n",
|
||||
pn[0], pn[1], pn[2], pn[3], ntohs(s->cli_addr.sin_port),
|
||||
tm->tm_mday, monthname[tm->tm_mon], tm->tm_year+1900,
|
||||
tm->tm_hour, tm->tm_min, tm->tm_sec,
|
||||
pxid, srv,
|
||||
s->logs.t_request,
|
||||
(s->logs.t_connect >= 0) ? s->logs.t_connect - s->logs.t_request : -1,
|
||||
(s->logs.t_data >= 0) ? s->logs.t_data - s->logs.t_connect : -1,
|
||||
(s->logs.t_connect >= 0) ? s->logs.t_connect : -1,
|
||||
s->logs.t_close,
|
||||
s->logs.status, s->logs.bytes,
|
||||
s->logs.cli_cookie ? s->logs.cli_cookie : "-",
|
||||
s->logs.srv_cookie ? s->logs.srv_cookie : "-",
|
||||
s->logs.bytes,
|
||||
sess_term_cond[(s->flags & SN_ERR_MASK) >> SN_ERR_SHIFT],
|
||||
sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT],
|
||||
(p->options & PR_O_COOK_ANY) ? sess_cookie[(s->flags & SN_CK_MASK) >> SN_CK_SHIFT] : '-',
|
||||
(p->options & PR_O_COOK_ANY) ? sess_set_cookie[(s->flags & SN_SCK_MASK) >> SN_SCK_SHIFT] : '-',
|
||||
uri);
|
||||
sess_fin_state[(s->flags & SN_FINST_MASK) >> SN_FINST_SHIFT]);
|
||||
}
|
||||
|
||||
s->logs.logwait = 0;
|
||||
@ -2793,6 +2787,11 @@ int process_cli(struct session *t) {
|
||||
}
|
||||
else if (c == CL_STDATA) {
|
||||
process_data:
|
||||
/* FIXME: this error handling is partly buggy because we always report
|
||||
* a 'DATA' phase while we don't know if the server was in IDLE, CONN
|
||||
* or HEADER phase. BTW, it's not logical to expire the client while
|
||||
* we're waiting for the server to connect.
|
||||
*/
|
||||
/* read or write error */
|
||||
if (t->res_cw == RES_ERROR || t->res_cr == RES_ERROR) {
|
||||
tv_eternity(&t->crexpire);
|
||||
@ -2808,8 +2807,6 @@ int process_cli(struct session *t) {
|
||||
/* last read, or end of server write */
|
||||
else if (t->res_cr == RES_NULL || s == SV_STSHUTW || s == SV_STCLOSE) {
|
||||
FD_CLR(t->cli_fd, StaticReadEvent);
|
||||
// if (req->l == 0) /* nothing to write on the server side */
|
||||
// FD_CLR(t->srv_fd, StaticWriteEvent);
|
||||
tv_eternity(&t->crexpire);
|
||||
shutdown(t->cli_fd, SHUT_RD);
|
||||
t->cli_state = CL_STSHUTR;
|
||||
@ -2826,8 +2823,6 @@ int process_cli(struct session *t) {
|
||||
/* read timeout */
|
||||
else if (tv_cmp2_ms(&t->crexpire, &now) <= 0) {
|
||||
FD_CLR(t->cli_fd, StaticReadEvent);
|
||||
// if (req->l == 0) /* nothing to write on the server side */
|
||||
// FD_CLR(t->srv_fd, StaticWriteEvent);
|
||||
tv_eternity(&t->crexpire);
|
||||
shutdown(t->cli_fd, SHUT_RD);
|
||||
t->cli_state = CL_STSHUTR;
|
||||
@ -2850,8 +2845,8 @@ int process_cli(struct session *t) {
|
||||
return 1;
|
||||
}
|
||||
|
||||
if (req->l >= req->rlim - req->data) {
|
||||
/* no room to read more data */
|
||||
if (req->l >= req->rlim - req->data || t->srv_state < SV_STDATA) {
|
||||
/* no room to read more data, or server not ready yet */
|
||||
if (FD_ISSET(t->cli_fd, StaticReadEvent)) {
|
||||
/* stop reading until we get some space */
|
||||
FD_CLR(t->cli_fd, StaticReadEvent);
|
||||
@ -2870,7 +2865,7 @@ int process_cli(struct session *t) {
|
||||
}
|
||||
|
||||
if ((rep->l == 0) ||
|
||||
((s == SV_STHEADERS) /* FIXME: this may be optimized && (rep->w == rep->h)*/)) {
|
||||
((s < SV_STDATA) /* FIXME: this may be optimized && (rep->w == rep->h)*/)) {
|
||||
if (FD_ISSET(t->cli_fd, StaticWriteEvent)) {
|
||||
FD_CLR(t->cli_fd, StaticWriteEvent); /* stop writing */
|
||||
tv_eternity(&t->cwexpire);
|
||||
@ -4672,10 +4667,12 @@ int cfg_parse_listen(char *file, int linenum, char **args) {
|
||||
else if (!strcmp(args[1], "forwardfor"))
|
||||
/* insert x-forwarded-for field */
|
||||
curproxy->options |= PR_O_FWDFOR;
|
||||
else if (!strcmp(args[1], "httplog")) {
|
||||
else if (!strcmp(args[1], "httplog"))
|
||||
/* generate a complete HTTP log */
|
||||
curproxy->to_log |= LW_DATE | LW_CLIP | LW_SVID | LW_REQ | LW_PXID | LW_RESP;
|
||||
}
|
||||
else if (!strcmp(args[1], "tcplog"))
|
||||
/* generate a detailed TCP log */
|
||||
curproxy->to_log |= LW_DATE | LW_CLIP | LW_SVID | LW_PXID;
|
||||
else if (!strcmp(args[1], "dontlognull")) {
|
||||
/* don't log empty requests */
|
||||
curproxy->options |= PR_O_NULLNOLOG;
|
||||
|
Loading…
Reference in New Issue
Block a user