Błąd sprawdzania poprawności sesji w Magento 1 EE v 1.14.3.x (i CE 1.9.3.x)

Opiekuję się sklepem Magento z 400-500 odwiedzających i 40-50 zamówień dziennie. Ostatnio system został zaktualizowany z Magento EE 1.14.2.4 do Magento EE 1.14.3.2 i zauważyłem dziwne wyjątki w logach:

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

Goniłem ten wyjątek i wiem, że jest on uruchamiany, ponieważ następujący kod sprawdzania poprawności sesji nie sprawdza poprawności sesji:

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() ) {

Ten if-block został dodany do pliku z najnowszą wersją Magento. I to najwyraźniej zmiana hamowania, zobacz więcej szczegółów poniżej.

Wyjątek zdarza się dość często, kilkanaście razy dziennie. ale nie jestem w stanie odtworzyć warunków, które prowadzą do wyjątku, chyba że dosłownie spełnię powyższy warunek. Wyjątki najczęściej występują na stronach ze szczegółowymi informacjami o produkcie i na ostatnim etapie realizacji jednej strony. Sklep jest sklepem b2b, użytkownik musi być zalogowany, aby zobaczyć stronę produktu lub aby móc dokonać zakupu, oznacza to, że użytkownik zostaje przekierowany na strony logowania, gdy sesja zostanie unieważniona / wygasła. W tej chwili ważniejsze jest dla mnie rozwiązanie tego problemu podczas realizacji transakcji.

Co dzieje się z perspektywy użytkownika: Użytkownik wypełnia koszyk, przechodzi do kasy i osiąga ostatni krok, a następnie naciska przycisk „Prześlij zamówienie” i nic się nie dzieje. Za kulisami JS Magento wykonuje żądanie AJAX i JS spodziewa się otrzymać JSON z powrotem, ale jeśli ten błąd się zdarzy, zostanie zwrócony kod HTML strony logowania, który nie może zostać przeanalizowany przez JavaScript i po prostu nic nie robi. To jest bardzo mylące dla użytkowników.

Cóż, to nie jest kompletny scenariusz dla użytkowników, skontaktowaliśmy się z użytkownikami i powiedzieli nam, że czekali kilka dni między wypełnieniem koszyka a złożeniem zamówienia, co dokładnie oznacza, że ​​trudno to zrozumieć, ponieważ ludzie po prostu tego nie pamiętają.

Żywotność sesji PHP - 350000 (~ 4 dni w sekundach) Żywotność plików cookie - 345600 (4 dni)

Oto aktualne pytanie: jak mogę dowiedzieć się, jakie zachowanie użytkownika prowadzi do wyjątku?

AKTUALIZACJA Jak dotąd wiem, że ten wyjątek zdarza się w następnych klasach zgodnie z otrzymanym żądaniem, co dla mnie nie znaczy nic.

/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

AKTUALIZACJA 2 : sesje są przechowywane w plikach i czyszczone przez moduł czyszczący sesje PHP, niezależnie od tego, czy jest to dobry wybór, czy nie, nie wchodzi w zakres tego pytania.

Po zaawansowanym debugowaniu, śledzeniu sesji i przemyśleniu całej tej magii udało mi się odtworzyć problem i zrozumieć jego przyczynę. Przygotowałem małą ilustrację czasową, którą możesz zobaczyć poniżej.

• czerwona flaga to moment zalogowania użytkownika i utworzenia sesji
• niebieska flaga to moment, w którym użytkownik otwiera stronę katalogu, załóżmy, że jest to strona kategorii, która jest otwarta.
• zielona flaga to moment, w którym użytkownik składa zamówienie ( /sales/order/save/...żądanie)

Oto jak odtworzyć:

1. Zanim zaczniesz: ustaw limit czasu sesji PHP i limitu czasu ciasteczka Magento na 1440, co jest domyślną wartością PHP.
2. Zabij wszystkie pliki cookie lub otwórz kartę incognito.
3. Przejdź do sklepu Magento i zaloguj się (patrz Flaga 1)
4. Przejrzyj katalog i dodaj niektóre produkty do koszyka (flaga 2)
5. Przejdź do kasy i złóż zamówienie. Zanotuj czas, kiedy to zrobiłeś. (Flaga 3)
6. Przejrzyj katalog i dodaj niektóre produkty do koszyka (flaga 4)
7. Odśwież stronę koszyka lub przeglądaj strony katalogu tak długo, aż upłynie limit czasu skonfigurowany dla ciasteczek magento (flagi 5-6). Pamiętaj, że czas między Flagą 7 a Flagą 3 powinien być dłuższy niż limit czasu ciasteczka.
8. Przejdź do kasy i złóż zamówienie (flaga 7). Złożenie zamówienia nie powiedzie się z powodu wyjątku opisanego w moim pytaniu powyżej.

Powód:

Istnieją pewne sesje, które są tworzone tylko na podstawie określonych żądań, np. Są tworzone Mage_Rss_Model_Sessiontylko podczas faktycznego finalizowania transakcji, a nie podczas przeglądania katalogu. Jednocześnie znacznik czasu wygaśnięcia sesji jest ustawiany tylko wtedy, gdy sesja została utworzona. Oznacza to, że jeśli między dwiema kasami było wystarczająco dużo czasu, a sesja nie została zabita w międzyczasie (ponieważ użytkownik wylogował się lub plik cookie wygasł), nowy kod Magento uzna tę sesję za niepotwierdzoną i zwróci wyjątek, co wydaje się dziwne mnie.

Jak naprawić:

Mam kilka opcji:

1. Poczekaj, aż Magento zareaguje na to i ponownie rozważy kod.
2. Tymczasem usuń ten kod.
3. Spróbuj ustawić limit czasu ciasteczka Magento na 0, jeśli jest to dla Ciebie opcja.

Jak to wymyśliłem:

1. Zacząłem od dodania następującego kodu do oryginalnego kodu 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
   );

   dało mi to dobry wgląd w klasy, których dotyczy problem, ich korelację i ile sesji upłynęło. Ale to nie wyjaśniało, dlaczego tak się dzieje i jakie działania użytkownika prowadzą do problemu.

2. Potem zacząłem zastanawiać się, jak mogę prześledzić wszystkie zmiany danych sesji i natknąłem się na to pytanie /superuser/368231/automatic-versioning-upon-file-change-modify-create-delete, które postanowiłem podać próba giti incronkombinacja, ale po zaimplementowaniu go i przetestowaniu w piaskownicy zdałem sobie sprawę, że zabraknie mi miejsca na dysku w produkcji bardzo szybko.

3. Postanowiłem zbudować mały skrypt PHP, który dekoduje dane sesji i zapisuje logi dla każdej sesji. Ten skrypt został wywołany przezincron

   <?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);

   a oto odpowiedni incrontabwpis

   /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 $@/$# $%

   próbka wyjściowa

   "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:

Aktualne wersje obu

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

nie są w stanie obsłużyć powyższego wyjątku podczas żądania AJAX. Nie wyświetlają dosłownie nic użytkownikowi, a użytkownik zostaje skutecznie wylogowany!

PPS:

najwyraźniej dotyczy to również wersji Magento CE 1.9.3.x, patrz https://github.com/OpenMage/magento-mirror/blame/magento-1.9/app/code/core/Mage/Core/Model/Session/Abstract/ Varien.php

PPPS:

Kiedy powiedziałem „Tymczasem usuń ten kod”. Miałem na myśli wyłączenie następującego bloku

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];
}

możesz to zrobić na wiele sposobów, w tym:

1. Po prostu usuwam ten bit z pliku
2. Komentując to
3. Wracając przed nim
4. Dokonywanie $this->useValidateSessionExpire()return true
5. ...
6. To programowanie - bądź kreatywny;)

6. Programuje - bądź kreatywny;)

Kolejny sposób, aby to naprawić (i poprawić sprawdzanie poprawności sesji)

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

Kod sesji przechowuje obecnie dane walidatora sesji w każdej przestrzeni nazw, a także sprawdza je przy każdym otwarciu przestrzeni nazw. Jest to złe, ponieważ:

1. Niezwykle nieefektywne miejsce do przechowywania sesji. Dane walidatora często obejmują ponad 50% przestrzeni używanej przez przestrzeń nazw, a gdy jest wiele przestrzeni nazw, stanowi to mnóstwo odpadów. Dzięki tej poprawce pamięć sesji może zostać znacznie zmniejszona, a przy korzystaniu z pamięci w pamięci, takiej jak Redis lub Memcached, ma to duże znaczenie.
2. Nieefektywność cykli obliczeniowych, ponieważ wiele przestrzeni nazw oznacza wielokrotne sprawdzanie poprawności i nie ma żadnego dobrego powodu, aby się od siebie różniły.
3. W rzeczywistości tworzy błędy, takie jak # 394, w których dane walidatora są aktualizowane dla niektórych żądań, ale nie dla innych (więc mogą się różnić, ale nie powinny). Nie testowałem, ale wierzę, że to rozwiąże ten problem.

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()

^{Źródło: https://github.com/OpenMage/magento-lts/commit/de06e671c09b375605a956e100911396822e276a}

Aktualizacja:

Napraw web/session/use_http_x_forwarded_for optionopcję wyłączoną ... https://github.com/OpenMage/magento-lts/pull/457/commits/ec8128b4605e82406679c3cd81244ddf3878c379

Jak przechowujesz sesje? (tj. w var / session / lub w DB, lub przy użyciu innych mechanizmów buforowania, takich jak Redis lub Memcached)

Niezależnie od tego, którego używasz, upewnij się, że Twoje uprawnienia do zapisu są prawidłowe var/session/(zwykle ustawione na 755 dla katalogów i 644 dla plików), lub jeśli używasz Redis lub Memcache, upewnij się, że ustawienia połączenia i limitu czasu są odpowiednie dla tych .

Inchoo ma dobry samouczek dla Redis: http://inchoo.net/magento/using-redis-cache-backend-and-session-storage-in-magento/

Jeśli korzystasz z Memcache, zapoznaj się z tym artykułem (odwołuje się do wersji 1.10, ale nie powinno się znacznie różnić): http://www.magestore.com/magento/magento-sessions-disappearing-w-memcache-turned-on.html

Ponadto, jeśli zdarza się, że używasz czegoś takiego jak Lakier, w przeszłości występowały problemy z sesjami, w których potrzebne były dziurkowanie niektórych stron.

Wreszcie, jeśli używasz systemu plików do sesji, możesz znaleźć ulgę, po prostu przełączając <session_save>węzeł local.xmlna „db” zamiast „pliki”.

Od tego <session_save><![CDATA[files]]></session_save>

Do tego <session_save><![CDATA[db]]></session_save>

Szczegół Antoniego Boritskiego jest fantastyczny. Ale zamiast wykluczyć ten blok, możesz zrobić kopię lokalną, aby nie edytować rdzenia i przepisać blok w następujący sposób:

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];
}

Zapewnia to, że porównanie między time () i znacznikiem_czasu sesji jest wykonywane tylko wtedy, gdy klucz istnieje, a gdy zostanie znaleziona sesja, która nie ma klucza (tj. Sesja wcześniejsza niż 1.9.3), klucz zostanie dodany.