Bug Last-Modified et If-Modified-Since : violations de la RFC 2616

[kerneis]

Bonjour,

j'ai de gros gros gros problèmes de cache avec mon site. Typiquement, il renvoie des 304 au navigateur alors même que le contenu a changé (donc le navigateur ne met pas à jour). Si je vide le cache du navigateur, la page mise à jour s'affiche. Du coup, j'ai fait quelques recherches, voici mes conclusions.

Configuration : Dotclear 2.1.5, lighttpd, blog accessible à  http://furet.kerneis.info. Accès avec Firefox, analyse des traces avec wireshark & logs lighttpd.

Voici un échange typique. On commence avec la racine (/) hors du cache. La première requête la récupère. La seconde requête la redemande, et elle n'est pas renvoyée (elle est dans le cache) alors que j'ai rajouté un billet dans dotclear dans l'intervalle. Puis, troisième échange, je vide le cache et je recharge : le billet apparaît. Commentaires ci-dessous.

GET / HTTP/1.1
Host: furet.kerneis.info
User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; fr; rv:1.9.0.13) Gecko/2009082005 Iceweasel/3.0.12 (Debian-3.0.12-1)
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: fr,fr-fr;q=0.8,en-us;q=0.5,en;q=0.3
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive

HTTP/1.1 200 OK
Transfer-Encoding: chunked
X-Powered-By: PHP/5.2.6-1+lenny3
Date: Fri, 04 Sep 2009 09:26:39 GMT
Last-Modified: Tue, 19 Jan 2038 03:14:07 GMT
Cache-Control: must-revalidate, max-age=0
Pragma: 
Content-Type: text/html; charset=UTF-8
ETag: "a53269a79ed23e9893a982af486efd33"
Server: lighttpd/1.4.19

[snip le contenu de la page]

[on ajoute un billet et on rafraîchit]

GET / HTTP/1.1
Host: furet.kerneis.info
User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; fr; rv:1.9.0.13) Gecko/2009082005 Iceweasel/3.0.12 (Debian-3.0.12-1)
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: fr,fr-fr;q=0.8,en-us;q=0.5,en;q=0.3
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive
If-Modified-Since: Tue, 19 Jan 2038 03:14:07 GMT
If-None-Match: "a53269a79ed23e9893a982af486efd33"
Cache-Control: max-age=0

HTTP/1.1 304 Not Modified
X-Powered-By: PHP/5.2.6-1+lenny3
Last-Modified: Tue, 19 Jan 2038 03:14:07 GMT
Cache-Control: must-revalidate, max-age=0
Pragma: 
Content-type: text/html
Date: Fri, 04 Sep 2009 09:26:51 GMT
Server: lighttpd/1.4.19

[on vide le cache et on rafraîchit]

GET / HTTP/1.1
Host: furet.kerneis.info
User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; fr; rv:1.9.0.13) Gecko/2009082005 Iceweasel/3.0.12 (Debian-3.0.12-1)
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: fr,fr-fr;q=0.8,en-us;q=0.5,en;q=0.3
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive

HTTP/1.1 200 OK
Transfer-Encoding: chunked
X-Powered-By: PHP/5.2.6-1+lenny3
Date: Fri, 04 Sep 2009 09:27:02 GMT
Last-Modified: Tue, 19 Jan 2038 03:14:07 GMT
Cache-Control: must-revalidate, max-age=0
Pragma: 
Content-Type: text/html; charset=UTF-8
ETag: "75e604d8080f1f8f98a96255b0aef06f"
Server: lighttpd/1.4.19

[snip le contenu de la page avec le nouveau billet]

Commentaires : Dotclear semble utiliser comme date pour Last-Modified la date la plus tardive possible en 32 bits (Tue, 19 Jan 2038 03:14:07 GMT). Ceci est une première violation de la RFC 2616 : « An origin server MUST NOT send a Last-Modified date which is later than the server's time of message origination. In such cases, where the resource's last modification would indicate some time in the future, the server MUST replace that date with the message origination date.» (section 14.29) Bon, on peut dire que c'est un bug de Lighttpd éventuellement, mais je ne sais pas trop si le serveur lit et réinterprète les headers écrits par les scripts PHP, je suppose que non, donc il faudrait corriger ça dans Dotclear.

Mais le vrai problème vient du fait que Dotclear ne renvoie pas la page mise à jour. Ceci est une seconde violation de la RFC 2616 (et en plus, c'est un vrai gros bug) : « If the request would normally result in anything other than a 200 (OK) status, or if the passed If-Modified-Since date is invalid, the response is exactly the same as for a normal GET. A date which is later than the server's current time is invalid.»

Donc Dotclear devrait renvoyer la page comme si rien n'était en cache, et non pas renvoyer un 304.

Je ne comprends pas que je sois le premier à avoir ce problème tellement il me semble énorme, donc j'ai peut-être planté ma configuration quelque part (dans les Rewrite Rules ?). Mais en tout cas, ce sont malgré tout des violations de la RFC 2616.

Le problème vient a priori de lib.http.php mais je ne saurais pas en dire plus.

Merci d'avance pour vos lumières (si le problème vient de moi) ou votre patch ;-)

[pep]

Tu l'as très bien dit : "Je ne comprends pas que je sois le premier à avoir ce problème tellement il me semble énorme".

Par contre, si tu avais pris le temps de regarder le code de la méthode http::cache(), tu aurais pu éviter la tirade sur les violations, hein. En fait, il nous arrive même de parfois la lire, cette RFC... ;-)

Il y a sans doute un souci avec ton installation, ou quelque chose de pas très clair qui met la méthode d'évaluation de cache HTTP de Dotclear 2 en défaut.

Le problème pour l'instant, c'est de pouvoir reproduire cela de mon côté...

[pep]

A première vue, la variable $ts déterminée dans la méthode http::cache() doit se voir attribuer une valeur erronée. Un workaround simple pourrait donc être de s'assurer que $ts <= time(), avant de balancer les entêtes.

Néanmoins, ça n'explique pas ce qui se passe dans le cas signalé (hors, peut-être, l'existence d'un billet publié avec une date loin dans le futur).

[kerneis]

Non, a priori je laisse mes billets avec les dates par défaut (donc au moment de la publication). Et puis la date en question est vraiment très particulière, c'est la fin d'Epoch, donc ça ressemble soit à un bug, soit à une tentative de mettre la date le plus loin possible pour éviter (???) une revalidation (enfin, ça ne marche pas à cause de la RFC, mais c'est l'idée qui m'est venue en premier lieu).

Je continue à chercher de mon côté (je vais notamment basculer sur Apache ce week-end juste pour voir si Lighttpd est en cause ; d'ailleurs, j'ai oublié de dire que j'utilise le module fastcgi).

[olivier]

Replying to kerneis:

... une tentative de mettre la date le plus loin possible pour éviter (???) une revalidation

Ça serait malvenu de faire ça. La date indiqué comme last-modified est la plus récente parmis les mtime des fichiers inclus et une date mise à jour automatiquement dans la db (à now). Rien d'autre.

[kerneis]

Bon, en tout cas pour ce qui est de renvoyer la page périmée, c'est bien la fonction cache qui est en cause, avec un cas $since = $ts = 2147483647 (ie. la date en 2038).

Si j'ajoute if ($since <= time() && $since >= $ts), le problème est effectivement résolu. Même si ça vaudrait le coup de trouver d'où ça vient, je pense qu'il est bon d'appliquer ce changement dans Dotclear, vu que ça blinde le code, respecte la RFC et ne peut pas faire de mal.

En fait, un meilleur patch (qui corrige les deux problèmes d'un coup, sauf erreur de ma part) est le suivant :

--- inc/clearbricks/common/lib.http.php.orig	2009-09-04 13:23:33.000000000 +0200
+++ inc/clearbricks/common/lib.http.php	2009-09-04 13:22:20.000000000 +0200
@@ -184,7 +184,7 @@
 		$array_ts = array_merge($mod_ts,$files);
 		
 		rsort($array_ts);
-		$ts = $array_ts[0];
+		$ts = min($array_ts[0], time());
 		
 		$since = null;
 		if (!empty($_SERVER['HTTP_IF_MODIFIED_SINCE'])) {
@@ -198,7 +198,7 @@
 		$headers[] = 'Cache-Control: must-revalidate, max-age='.abs((integer) self::$cache_max_age);
 		$headers[] = 'Pragma:';
 		
-		if ($since >= $ts)
+		if ($since <= time() && $since >= $ts)
 		{
 			self::head(304,'Not Modified');
 			foreach ($headers as $v) {

En tout cas, chez moi ça marche donc je l'ai appliqué :-)

[kerneis]

Et si vous voulez que je fasse d'autres tests pour déterminer l'origine du problème, dites-moi (là, je n'ai plus trop d'idées mais vous connaissez Dotclear bien mieux que moi).

[kerneis]

J'ai trouvé le problème : le thème Fallseason, lorsque je le dézippe, crée ses fichiers avec des dates aberrantes (en 2038, ou 2092 sur un système 64 bits). Ce sont ces dates qui se retrouvent être la fin d'Epoch qui provoquent le débordement intempestif.

 http://themes.dotaddict.org/galerie-dc2/details/FallSeason

Mon patch reste intéressant pour se prémunir contre des fichiers avec de tels problèmes.

[xave]

fixed in Clearbricks commit 220.