Échec de validation de session dans Magento 1 EE v 1.14.3.x (et CE 1.9.3.x)

Je m'occupe d'une boutique Magento avec 400-500 visiteurs et 40-50 commandes par jour. Récemment, le système a été mis à niveau de Magento EE 1.14.2.4 vers Magento EE 1.14.3.2 et j'ai remarqué quelques exceptions étranges dans les journaux:

exception 'Mage_Core_Model_Session_Exception' in
/var/www/.../app/code/core/Mage/Core/Model/Session/Abstract/Varien.php:418

Je cherchais cette exception et je sais qu'elle est déclenchée car le code de validation de session suivant ne parvient pas à valider la session:

class Mage_Core_Model_Session_Abstract_Varien extends Varien_Object
{
// ...
    protected function _validate()
    {
//    ...
        if ($this->useValidateSessionExpire()
            && isset($sessionData[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP])
            && $sessionData[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP] < time() ) {

Ce bloc if a été ajouté au fichier avec la dernière version de Magento. Et c'est apparemment un changement de freinage, voir plus de détails ci-dessous.

L'exception se produit assez souvent, comme une douzaine de fois par jour. mais je ne suis pas en mesure de recréer des conditions qui conduisent à l'exception, sauf si je mets littéralement vrai dans la condition ci-dessus. Les exceptions se produisent le plus souvent sur les pages de détails du produit et à la dernière étape de la vérification d'une page. La boutique est une boutique b2b, l'utilisateur doit être connecté pour voir la page du produit ou pour pouvoir commander, signifie que l'utilisateur est redirigé vers les pages de connexion lorsque la session est invalidée / expirée. Pour le moment, il est plus important pour moi de résoudre ce problème lors du paiement.

Que se passe-t-il du point de vue de l'utilisateur: l'utilisateur remplit le panier, passe à la caisse et atteint la dernière étape, puis il / elle clique sur le bouton "soumettre la commande" et rien ne se passe. Dans les coulisses, JS de Magento effectue une requête AJAX et JS s'attend à recevoir JSON en retour, mais si cette erreur se produit, le code HTML de la page de connexion est renvoyé, ce qui ne peut pas être analysé par JavaScript et ne fait rien. C'est super déroutant pour les utilisateurs.

Eh bien, ce n'est pas un scénario utilisateur complet, nous avons contacté les utilisateurs et ils nous ont dit qu'ils ont attendu quelques jours entre le remplissage du panier et la soumission de la commande, ce que cela signifie exactement est difficile à comprendre, car les gens ne s'en souviennent tout simplement pas.

Durée de vie de la session PHP - 350000 (~ 4 jours en secondes) Durée de vie du cookie - 345600 (4 jours)

Voici la vraie question: comment puis-je savoir quel type de comportement utilisateur conduit à l'exception?

MISE À JOUR Jusqu'à présent, je sais que l'exception se produit dans les classes suivantes en fonction de la demande faite, pour moi cela ne signifie malheureusement rien.

/catalogsearch/result/?q=…    Mage_Core_Model_Session
/checkout/cart/               Mage_Core_Model_Session
/checkout/onepage/saveOrder/… Mage_Rss_Model_Session
/customer/account/loginPost/  Mage_Core_Model_Session
/customer/account/loginPost/  Mage_Reports_Model_Session
/customer/account/logout/     Mage_Reports_Model_Session
/catalog/product/view/…       Mage_Reports_Model_Session
/catalog/product/view/…       Mage_Tag_Model_Session

MISE À JOUR 2 : les sessions sont stockées dans des fichiers et nettoyées par le garbage collector de la session PHP, que ce soit un bon choix ou non est hors de portée de cette question.

Après un débogage avancé, un suivi de session et une réflexion sur toute cette magie, j'ai pu reproduire le problème et en comprendre la raison. J'ai préparé une petite illustration de timing, vous pouvez la voir ci-dessous.

• le drapeau rouge est le moment de la connexion de l'utilisateur et de la création de la session
• le drapeau bleu est le moment où l'utilisateur ouvre la page du catalogue, supposons que c'est une page de catégorie qui est ouverte.
• le drapeau vert est le moment où l'utilisateur soumet la commande ( /sales/order/save/...demande)

Voici comment reproduire:

1. Avant de commencer: définissez le délai d'expiration de votre session PHP et le délai d'expiration du cookie Magento sur 1440, ce qui est une valeur PHP par défaut.
2. Tuez tous vos cookies ou ouvrez l'onglet incognito.
3. Accédez à votre boutique Magento et connectez-vous (voir indicateur 1)
4. Parcourez le catalogue et ajoutez des produits au panier (Drapeau 2)
5. Passez à la caisse et soumettez une commande. Notez l'heure à laquelle vous l'avez fait. (Drapeau 3)
6. Parcourez le catalogue et ajoutez des produits au panier (Drapeau 4)
7. Continuez à actualiser votre page de panier ou à parcourir les pages de catalogue si longtemps que le délai d'attente que vous avez configuré pour les cookies magento expire (indicateurs 5-6). Notez que le temps entre le drapeau 7 et le drapeau 3 doit être supérieur au délai d'expiration du cookie.
8. Passez à la caisse et soumettez une commande (indicateur 7). La soumission de la commande échouera en raison de l'exception décrite dans ma question ci-dessus.

Raison:

Il y a certaines sessions qui ne sont instanciées que sur des demandes données, par exemple, qui Mage_Rss_Model_Sessionne sont instanciées que lors du paiement réel et non lors de la navigation dans le catalogue. En même temps, l'horodatage d'expiration de la session n'est défini que lorsque la session a été instanciée. Cela signifie que s'il y a eu suffisamment de temps entre deux extractions et que la session n'a pas été interrompue entre-temps (parce que l'utilisateur s'est déconnecté ou que le cookie a expiré), le nouveau code Magento considérera cette session comme ne passant pas la validation et lèvera une exception, ce qui semble quelque peu étrange à moi.

Comment réparer:

Eh bien, j'ai peu d'options:

1. Attendez que Magento réagisse à ce sujet et reconsidère ce code.
2. En attendant, supprimez ce code.
3. Essayez de définir le délai d'expiration du cookie Magento sur 0 si c'est une option pour vous.

Comment ai-je compris:

1. J'ai commencé par ajouter ce qui suit au code d'origine de Mage_Core_Model_Session_Abstract_Varien

   Mage::log(
       sprintf(
           'useValidateSessionExpire fail "%s" "%d" "%d" "%s" "%s" "%s"',
           print_r($sessionData[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP], 1),
           time(),
           $this->_time,
           get_class($this),
           session_name(),
           session_id()
       ),
       Zend_Log::DEBUG,
       'session-validation.log',
       true
   );

   cela m'a donné un bon aperçu des classes affectées et de leur corrélation et de la durée de la session. Mais cela n'expliquait pas pourquoi cela se produisait et quelles actions des utilisateurs entraînaient le problème.

2. Ensuite, j'ai commencé à réfléchir à la façon de suivre toutes les modifications apportées aux données de session et j'ai rencontré cette question /superuser/368231/automatic-versioning-upon-file-change-modify-create-delete que j'ai décidé de donner. un essai gitet une incroncombinaison, mais après l'avoir implémenté et testé dans un bac à sable, j'ai réalisé que je manquerai d'espace disque très rapidement en production.

3. J'ai décidé de construire un petit script PHP qui décodera les données de session et rédigera des journaux pour chaque session. Ce script a été appelé parincron

   <?php
   //log-session-data-change.php
   
   $sessionLogStoragePath = '/var/www/html/logged-session-storage/';
   
   $sessionFilePath = $argv[1];
   $sessionOperationType = $argv[2];
   $sessionFileName = basename($sessionFilePath);
   
   session_start();
   session_decode(file_get_contents($sessionFilePath));
   
   $logString = sprintf(
     '"%s","%s","%s",""' . PHP_EOL,
     date(DateTime::COOKIE),
     $sessionOperationType,
     $sessionFileName
   );
   
   if (file_exists($sessionFilePath)) {
     session_start();
     session_decode(file_get_contents($sessionFilePath));
   
     foreach ($_SESSION as $name => $data) {
       $value = '<empty>';
       if (isset($data['_session_validator_data']) && isset($data['_session_validator_data']['session_expire_timestamp'])) {
         $value = $data['_session_validator_data']['session_expire_timestamp'];
       }
       $logString .= sprintf(
         '"","","","%s","%s"' . PHP_EOL,
         $name,
         $value
       );
     }
   }
   
   file_put_contents($sessionLogStoragePath . $sessionFileName, $logString, FILE_APPEND);

   et voici l' incrontabentrée correspondante

   /var/www/html/magento-doc-root/var/session IN_MODIFY,IN_CREATE,IN_DELETE,IN_MOVE /usr/bin/php /var/www/html/log-session-data-change.php $@/$# $%

   exemple de sortie

   "Wednesday, 05-Apr-2017 18:09:06 CEST","IN_MODIFY","sess_94rfglnua0phncmp98hbr3k524",""
   "","","","core","1491408665"
   "","","","customer_base","1491408665"
   "","","","catalog","1491408665"
   "","","","checkout","1491408665"
   "","","","reports","1491408494"
   "","","","store_default","1491408665"
   "","","","rss","1491408524"
   "","","","admin","1491408524"

PS:

Versions actuelles des deux

skin/frontend/enterprise/default/js/opcheckout.js 
src/skin/frontend/base/default/js/opcheckout.js

ne sont pas en mesure de gérer l'exception ci-dessus lors de la demande AJAX. Ils n'affichent littéralement rien à l'utilisateur, tandis que l'utilisateur est effectivement déconnecté!

PPS:

apparemment, les versions de Magento CE 1.9.3.x sont également affectées, voir https://github.com/OpenMage/magento-mirror/blame/magento-1.9/app/code/core/Mage/Core/Model/Session/Abstract/ Varien.php

PPPS:

Quand j'ai dit "Supprimez ce code en attendant." Je voulais dire exclure le bloc suivant

if ($this->useValidateSessionExpire()
    && isset($sessionData[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP])
    && $sessionData[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP] < time() ) {
    return false;
} else {
    $this->_data[self::VALIDATOR_KEY][self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP]
        = $validatorData[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP];
}

vous pouvez le faire de différentes manières, notamment:

1. Supprimer simplement ce bit du fichier
2. Commenter
3. Retour avant lui
4. Rendre le $this->useValidateSessionExpire()retour vrai
5. ...
6. C'est de la programmation - soyez créatif;)

6. C'est de la programmation - soyez créatif;)

Une autre façon de résoudre ce problème (et d'améliorer la validation de la session)

ColinM @ https://github.com/OpenMage/magento-lts

Le code de session stocke actuellement les données du validateur de session dans chaque espace de noms et les valide également chaque fois que l'espace de noms est inité. C'est mauvais parce que:

1. Espace de stockage de session extrêmement inefficace. Les données du validateur représentent souvent plus de 50% de l'espace utilisé par un espace de noms et lorsqu'il y a de nombreux espaces de noms, cela représente une tonne de déchets. Le stockage de session peut être considérablement réduit avec ce correctif et lorsque vous utilisez un stockage en mémoire comme Redis ou Memcached, cela compte beaucoup.
2. Les cycles de calcul sont inefficaces car plusieurs espaces de noms signifient plusieurs validations et il n'y a aucune bonne raison pour que ces différences diffèrent les unes des autres.
3. Crée en fait des bogues tels que # 394 où les données du validateur sont mises à jour sur certaines demandes mais pas sur d'autres (donc elles peuvent différer mais ne devraient pas). Je n'ai pas testé, mais je pense que cela résoudra également ce problème.

diff --git a/app/code/core/Mage/Core/Model/Session/Abstract/Varien.php b/app/code/core/Mage/Core/Model/Session/Abstract/Varien.php
index 45d736543..ea6b464f1 100644
--- a/app/code/core/Mage/Core/Model/Session/Abstract/Varien.php
+++ b/app/code/core/Mage/Core/Model/Session/Abstract/Varien.php
@@ -35,6 +35,9 @@ class Mage_Core_Model_Session_Abstract_Varien extends Varien_Object
     const VALIDATOR_SESSION_EXPIRE_TIMESTAMP    = 'session_expire_timestamp';
     const SECURE_COOKIE_CHECK_KEY               = '_secure_cookie_check';

+    /** @var bool Flag true if session validator data has already been evaluated */
+    protected static $isValidated = FALSE;
+
     /**
      * Map of session enabled hosts
      * @example array('host.name' => true)
@@ -406,16 +409,21 @@ public function getValidateHttpUserAgentSkip()
     /**
      * Validate session
      *
-     * @param string $namespace
+     * @throws Mage_Core_Model_Session_Exception
      * @return Mage_Core_Model_Session_Abstract_Varien
      */
     public function validate()
     {
-        if (!isset($this->_data[self::VALIDATOR_KEY])) {
-            $this->_data[self::VALIDATOR_KEY] = $this->getValidatorData();
+        // Backwards compatibility with legacy sessions (validator data stored per-namespace)
+        if (isset($this->_data[self::VALIDATOR_KEY])) {
+            $_SESSION[self::VALIDATOR_KEY] = $this->_data[self::VALIDATOR_KEY];
+            unset($this->_data[self::VALIDATOR_KEY]);
+        }
+        if (!isset($_SESSION[self::VALIDATOR_KEY])) {
+            $_SESSION[self::VALIDATOR_KEY] = $this->getValidatorData();
         }
         else {
-            if (!$this->_validate()) {
+            if ( ! self::$isValidated && ! $this->_validate()) {
                 $this->getCookie()->delete(session_name());
                 // throw core session exception
                 throw new Mage_Core_Model_Session_Exception('');
@@ -432,8 +440,9 @@ public function validate()
      */
     protected function _validate()
     {
-        $sessionData = $this->_data[self::VALIDATOR_KEY];
+        $sessionData = $_SESSION[self::VALIDATOR_KEY];
         $validatorData = $this->getValidatorData();
+        self::$isValidated = TRUE; // Only validate once since the validator data is the same for every namespace

         if ($this->useValidateRemoteAddr()
                 && $sessionData[self::VALIDATOR_REMOTE_ADDR_KEY] != $validatorData[self::VALIDATOR_REMOTE_ADDR_KEY]) {
@@ -444,10 +453,8 @@ protected function _validate()
             return false;
         }

-        $sessionValidateHttpXForwardedForKey = $sessionData[self::VALIDATOR_HTTP_X_FORVARDED_FOR_KEY];
-        $validatorValidateHttpXForwardedForKey = $validatorData[self::VALIDATOR_HTTP_X_FORVARDED_FOR_KEY];
         if ($this->useValidateHttpXForwardedFor()
-            && $sessionValidateHttpXForwardedForKey != $validatorValidateHttpXForwardedForKey ) {
+                && $sessionData[self::VALIDATOR_HTTP_X_FORVARDED_FOR_KEY] != $validatorData[self::VALIDATOR_HTTP_X_FORVARDED_FOR_KEY]) {
             return false;
         }
         if ($this->useValidateHttpUserAgent()

^{Source: https://github.com/OpenMage/magento-lts/commit/de06e671c09b375605a956e100911396822e276a}

Mise à jour:

Correction de l' web/session/use_http_x_forwarded_for optionoption désactivée ... https://github.com/OpenMage/magento-lts/pull/457/commits/ec8128b4605e82406679c3cd81244ddf3878c379

Comment stockez-vous les sessions? (c'est-à-dire dans var / session / ou dans la base de données, ou en utilisant d'autres moteurs de mise en cache tels que Redis ou Memcached)

Quel que soit le système utilisé, assurez-vous que vos autorisations d'écriture sont correctes var/session/(généralement définies sur 755 pour les répertoires et 644 pour les fichiers), ou si vous utilisez Redis ou Memcache, assurez-vous que vos paramètres de connexion et de délai d'attente sont bons pour ceux .

Inchoo a un bon tutoriel pour Redis: http://inchoo.net/magento/using-redis-cache-backend-and-session-storage-in-magento/

Si vous utilisez Memcache, consultez cet article (il fait référence à la v1.10, mais ne devrait pas être très différent): http://www.magestore.com/magento/magento-sessions-disappearing-with-memcache-turned-on.html

De plus, si vous utilisez quelque chose comme Varnish, il y a eu des problèmes dans le passé avec des sessions où il était nécessaire de perforer certaines pages.

Enfin, si vous utilisez le système de fichiers pour vos sessions, vous pourriez trouver un soulagement en basculant simplement le <session_save>nœud de votre local.xmlsur "db" au lieu de "fichiers".

De cela <session_save><![CDATA[files]]></session_save>

Pour ça <session_save><![CDATA[db]]></session_save>

Le détail d'Anton Boritskiy est fantastique. Mais au lieu d'exclure ce bloc, vous pouvez faire une copie locale afin de ne pas éditer le noyau et réécrire le bloc comme:

if ($this->useValidateSessionExpire() ) {
    // If the VALIDATOR_SESSION_EXPIRE_TIMESTAMP key is not set, do it now
    if( !isset($sessionData[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP]) ) {
        // $this->_data is a reference to the $_SESSION variable so it will be automatically modified
        $this->_data[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP] = time() + $this->getCookie()->getLifetime();
        return true;
    } elseif ( $sessionData[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP] < time() ) {
        return false;
    }
} else {
    $this->_data[self::VALIDATOR_KEY][self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP]
        = $validatorData[self::VALIDATOR_SESSION_EXPIRE_TIMESTAMP];
}

Cela garantit que la comparaison entre time () et session_expire_timestamp n'est exécutée que lorsque la clé existe et que lorsqu'une session est trouvée qui n'a pas la clé (c'est-à-dire une session antérieure à la version 1.9.3), la clé est ajoutée.