{"action":"created","issue":{"url":"https://api.github.com/repos/nexcess/magento-turpentine/issues/1023","labels_url":"https://api.github.com/repos/nexcess/magento-turpentine/issues/1023/labels{/name}","comments_url":"https://api.github.com/repos/nexcess/magento-turpentine/issues/1023/comments","events_url":"https://api.github.com/repos/nexcess/magento-turpentine/issues/1023/events","html_url":"https://github.com/nexcess/magento-turpentine/issues/1023","id":118689598,"number":1023,"title":"Invalid Form Key - Magento 1.9.2.1","user":{"login":"vithefiddler","id":191704,"avatar_url":"https://avatars.githubusercontent.com/u/191704?v=3","gravatar_id":"","url":"https://api.github.com/users/vithefiddler","html_url":"https://github.com/vithefiddler","followers_url":"https://api.github.com/users/vithefiddler/followers","following_url":"https://api.github.com/users/vithefiddler/following{/other_user}","gists_url":"https://api.github.com/users/vithefiddler/gists{/gist_id}","starred_url":"https://api.github.com/users/vithefiddler/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/vithefiddler/subscriptions","organizations_url":"https://api.github.com/users/vithefiddler/orgs","repos_url":"https://api.github.com/users/vithefiddler/repos","events_url":"https://api.github.com/users/vithefiddler/events{/privacy}","received_events_url":"https://api.github.com/users/vithefiddler/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":0,"created_at":"2015-11-24T19:51:47Z","updated_at":"2015-11-24T19:55:23Z","closed_at":null,"body":"We are having an intermittent error on our site (2-10 times per day) where someone is unable to add an item to their cart in magento. I haven't been able to replicate the behavior myself, but one of our staff members has seen the behavior on his tablet, and I'm getting the error messages in the log, and our office staff is getting phone calls from people who are trying to place orders and can't. The general process and behavior is: \r\n\r\n1. Add an item to the cart. \r\n2. The cart is empty and the below message is logged.\r\n\r\nThe current configuration is:\r\nMagento 1.9.2.1\r\nVarnish: 3.0.X\r\nTurpentine: 0.6.7\r\n\r\nThis bug report for turpentine is the closest thing I've found to a discussion of the issue:\r\nhttps://github.com/nexcess/magento-turpentine/issues/345\r\n\r\nObviously inability to add a product to cart is a big problem on an ecommerce site. I really appreciate your help in solving this issue.\r\n\r\nThis is what's currently in my URL Blacklist:\r\ncron\\.php\r\ncron\\.sh\r\nrobots\\.txt\r\nsitemap\\.xml\r\nsitemap\\.xml\\.gz\r\ncatalogsearch\r\njs\\/amasty\\/\\*\r\ncheckout\\/\\*\r\ncart\r\ncustomer\r\naccount\r\najax*\r\n\r\nThe below error is what shows up in the log. \r\n\r\nURL: http://www.americanlegacyfishing.com/checkout/cart/ajaxDelete/id/226243/uenc/aHR0cDovL3d3dy5hbWVyaWNhbmxlZ2FjeWZpc2hpbmcuY29tL2Zpc2hpbmcvZmlzaGluZy1yb2RzL3Nob3BieS9nX2xvb21pcy5odG1sP3V0bV9zb3VyY2U9TmV3cytCbGFzdCtOb3ZlbWJlcisyNCUyQysyMDE1LTImdXRtX2NhbXBhaWduPU5vdmVtYmVyKzI0cmQmdXRtX21lZGl1bT1lbWFpbA,,/\r\nIP Address: 166.137.139.76\r\nTime: 2015-11-24 19:05:43 GMT\r\nError:\r\nInvalid form key\r\n\r\nTrace:\r\n#0 /home/newagcom/public_html/app/code/core/Mage/Checkout/controllers/CartController.php(604): Mage::throwException('Invalid form ke...')\r\n#1 /home/newagcom/public_html/app/code/core/Mage/Core/Controller/Varien/Action.php(418): Mage_Checkout_CartController->ajaxDeleteAction()\r\n#2 /home/newagcom/public_html/app/code/core/Mage/Core/Controller/Varien/Router/Standard.php(254): Mage_Core_Controller_Varien_Action->dispatch('ajaxDelete')\r\n#3 /home/newagcom/public_html/app/code/core/Mage/Core/Controller/Varien/Front.php(172): Mage_Core_Controller_Varien_Router_Standard->match(Object(Mage_Core_Controller_Request_Http))\r\n#4 /home/newagcom/public_html/app/code/core/Mage/Core/Model/App.php(365): Mage_Core_Controller_Varien_Front->dispatch()\r\n#5 /home/newagcom/public_html/app/Mage.php(684): Mage_Core_Model_App->run(Array)\r\n#6 /home/newagcom/public_html/index.php(91): Mage::run('', 'store')\r\n#7 {main}\r\n\r\nThis is what's in the main varnish vcl:\r\nC{\r\n#include <stdlib.h>\r\n#include <stdio.h>\r\n#include <time.h>\r\n#include <pthread.h>\r\nstatic pthread_mutex_t lrand_mutex = PTHREAD_MUTEX_INITIALIZER;\r\nvoid generate_uuid(char* buf) {\r\npthread_mutex_lock(&lrand_mutex);\r\nlong a = lrand48();\r\nlong b = lrand48();\r\nlong c = lrand48();\r\nlong d = lrand48();\r\npthread_mutex_unlock(&lrand_mutex);\r\nsprintf(buf, \"frontend=%08lx%04lx%04lx%04lx%04lx%08lx\",\r\na,\r\nb & 0xffff,\r\n(b & ((long)0x0fff0000) >> 16) | 0x4000,\r\n(c & 0x0fff) | 0x8000,\r\n(c & (long)0xffff0000) >> 16,\r\nd\r\n);\r\nreturn;\r\n}\r\n}C\r\nimport std;\r\nsub vcl_recv {\r\nif(req.http.User-Agent ~ \"iP(?:hone|ad|od)|BlackBerry|Palm|Googlebot-Mobile|Mobile|mobile|mobi|Windows Mobile|Safari Mobile|Android|Opera (?:Mini|Mobi)\") {\r\nreturn(pipe);\r\n}\r\nif(req.http.Host ~ \"test\\.americanlegacyfishing\\.com\") {\r\nreturn(pipe);\r\n}\r\n}\r\nbackend default {\r\n.host = \"198.91.28.69\";\r\n.port = \"8080\";\r\n.first_byte_timeout = 300s;\r\n.between_bytes_timeout = 300s;\r\n}\r\nbackend admin {\r\n.host = \"198.91.28.69\";\r\n.port = \"8080\";\r\n.first_byte_timeout = 21600s;\r\n.between_bytes_timeout = 21600s;\r\n}\r\nacl crawler_acl {\r\n\"127.0.0.1\";\r\n}\r\nacl debug_acl {\r\n\"101.99.23.40\";\r\n\"113.190.242.147\";\r\n}\r\n/* -- REMOVED\r\nsub generate_session {\r\nif (req.url ~ \".*[&?]SID=([^&]+).*\") {\r\nset req.http.X-Varnish-Faked-Session = regsub(\r\nreq.url, \".*[&?]SID=([^&]+).*\", \"frontend=\\1\");\r\n} else {\r\nC{\r\nchar uuid_buf [50];\r\ngenerate_uuid(uuid_buf);\r\nVRT_SetHdr(sp, HDR_REQ,\r\n\"\\030X-Varnish-Faked-Session:\",\r\nuuid_buf,\r\nvrt_magic_string_end\r\n);\r\n}C\r\n}\r\nif (req.http.Cookie) {\r\nstd.collect(req.http.Cookie);\r\nset req.http.Cookie = req.http.X-Varnish-Faked-Session +\r\n\"; \" + req.http.Cookie;\r\n} else {\r\nset req.http.Cookie = req.http.X-Varnish-Faked-Session;\r\n}\r\n}\r\nsub generate_session_expires {\r\nC{\r\ntime_t now = time(NULL);\r\nstruct tm now_tm = *gmtime(&now);\r\nnow_tm.tm_sec += 21600;\r\nmktime(&now_tm);\r\nchar date_buf [50];\r\nstrftime(date_buf, sizeof(date_buf)-1, \"%a, %d-%b-%Y %H:%M:%S %Z\", &now_tm);\r\nVRT_SetHdr(sp, HDR_RESP,\r\n\"\\031X-Varnish-Cookie-Expires:\",\r\ndate_buf,\r\nvrt_magic_string_end\r\n);\r\n}C\r\n}\r\n-- */\r\nsub vcl_recv {\r\nif (req.restarts == 0) {\r\nif (req.http.X-Forwarded-For) {\r\nset req.http.X-Forwarded-For =\r\nreq.http.X-Forwarded-For + \", \" + client.ip;\r\n} else {\r\nset req.http.X-Forwarded-For = client.ip;\r\n}\r\n}\r\nif(false) {\r\nset req.http.X-Varnish-Origin-Url = req.url;\r\n}\r\nif (req.http.Accept-Encoding) {\r\nif (req.http.Accept-Encoding ~ \"gzip\") {\r\nset req.http.Accept-Encoding = \"gzip\";\r\n} else if (req.http.Accept-Encoding ~ \"deflate\") {\r\nset req.http.Accept-Encoding = \"deflate\";\r\n} else {\r\nunset req.http.Accept-Encoding;\r\n}\r\n}\r\nif (req.http.User-Agent ~ \"iP(?:hone|ad|od)|BlackBerry|Palm|Googlebot-Mobile|Mobile|mobile|mobi|Windows Mobile|Safari Mobile|Android|Opera (?:Mini|Mobi)\") {\r\nset req.http.X-Normalized-User-Agent = \"mobile\";\r\n} else if (req.http.User-Agent ~ \"MSIE\") {\r\nset req.http.X-Normalized-User-Agent = \"msie\";\r\n} else if (req.http.User-Agent ~ \"Firefox\") {\r\nset req.http.X-Normalized-User-Agent = \"firefox\";\r\n} else if (req.http.User-Agent ~ \"Chrome\") {\r\nset req.http.X-Normalized-User-Agent = \"chrome\";\r\n} else if (req.http.User-Agent ~ \"Safari\") {\r\nset req.http.X-Normalized-User-Agent = \"safari\";\r\n} else if (req.http.User-Agent ~ \"Opera\") {\r\nset req.http.X-Normalized-User-Agent = \"opera\";\r\n} else {\r\nset req.http.X-Normalized-User-Agent = \"other\";\r\n}\r\nif (!true || req.http.Authorization ||\r\nreq.request !~ \"^(GET|HEAD|OPTIONS)$\" ||\r\nreq.http.Cookie ~ \"varnish_bypass=1\") {\r\nif (req.url ~ \"^(/media/|/skin/|/js/|/)(?:(?:index|litespeed)\\.php/)?alfc-admin\") {\r\nset req.backend = admin;\r\n}\r\nreturn (pipe);\r\n}\r\nset req.url = regsuball(req.url, \"([^:])//+\", \"\\1/\");\r\nif (req.url ~ \"^(/media/|/skin/|/js/|/)(?:(?:index|litespeed)\\.php/)?\") {\r\nset req.http.X-Turpentine-Secret-Handshake = \"1\";\r\nif (req.url ~ \"^(/media/|/skin/|/js/|/)(?:(?:index|litespeed)\\.php/)?alfc-admin\") {\r\nset req.backend = admin;\r\nreturn (pipe);\r\n}\r\nif (req.http.Cookie ~ \"\\bcurrency=\") {\r\nset req.http.X-Varnish-Currency = regsub(\r\nreq.http.Cookie, \".*\\bcurrency=([^;]*).*\", \"\\1\");\r\n}\r\nif (req.http.Cookie ~ \"\\bstore=\") {\r\nset req.http.X-Varnish-Store = regsub(\r\nreq.http.Cookie, \".*\\bstore=([^;]*).*\", \"\\1\");\r\n}\r\nif (req.url ~ \"/turpentine/esi/get(?:Block|FormKey)/\") {\r\nset req.http.X-Varnish-Esi-Method = regsub(\r\nreq.url, \".*/method/(\\w+)/.*\", \"\\1\");\r\nset req.http.X-Varnish-Esi-Access = regsub(\r\nreq.url, \".*/access/(\\w+)/.*\", \"\\1\");\r\nif (req.http.X-Varnish-Esi-Method == \"esi\" && req.esi_level == 0 &&\r\n!(false || client.ip ~ debug_acl)) {\r\nerror 403 \"External ESI requests are not allowed\";\r\n}\r\n}\r\nif (req.http.Cookie !~ \"frontend=\" && !req.http.X-Varnish-Esi-Method) {\r\nif (client.ip ~ crawler_acl ||\r\nreq.http.User-Agent ~ \"^(?:ApacheBench/.*|.*Googlebot.*|JoeDog/.*Siege.*|magespeedtest\\.com|Nexcessnet_Turpentine/.*|Baidu/.*|Bing/.*|Yandex/.*|Yahoo/.*)$\") {\r\nset req.http.Cookie = \"frontend=crawler-session\";\r\n} else {\r\nreturn (pipe);\r\n}\r\n}\r\nif (true &&\r\nreq.url ~ \".*\\.(?:css|js|jpe?g|png|gif|ico|swf)(?=\\?|&|$)\") {\r\nunset req.http.Cookie;\r\nunset req.http.X-Varnish-Faked-Session;\r\nreturn (lookup);\r\n}\r\nif (req.url ~ \"^(/media/|/skin/|/js/|/)(?:(?:index|litespeed)\\.php/)?(?:alfc-admin|api|cron\\.php|cron\\.sh|robots\\.txt|sitemap\\.xml|sitemap\\.xml\\.gz|catalogsearch|js\\/amasty\\/\\*|checkout\\/\\*|cart|customer|account|ajax*)\" ||\r\nreq.url ~ \"\\?.*__from_store=\") {\r\nreturn (pipe);\r\n}\r\nif (true &&\r\nreq.url ~ \"(?:[?&](?:__SID|XDEBUG_PROFILE)(?=[&=]|$))\") {\r\nreturn (pass);\r\n}\r\nif (true && req.url ~ \"[?&](utm_source|utm_medium|utm_campaign|utm_content|utm_term|gclid|cx|ie|cof|siteurl)=\") {\r\nset req.url = regsuball(req.url, \"(?:(\\?)?|&)(?:utm_source|utm_medium|utm_campaign|utm_content|utm_term|gclid|cx|ie|cof|siteurl)=[^&]+\", \"\\1\");\r\nset req.url = regsuball(req.url, \"(?:(\\?)&|\\?$)\", \"\\1\");\r\n}\r\nif(false) {\r\nset req.http.X-Varnish-Cache-Url = req.url;\r\nset req.url = req.http.X-Varnish-Origin-Url;\r\nunset req.http.X-Varnish-Origin-Url;\r\n}\r\nreturn (lookup);\r\n}\r\n}\r\nsub vcl_pipe {\r\nunset bereq.http.X-Turpentine-Secret-Handshake;\r\nset bereq.http.Connection = \"close\";\r\n}\r\nsub vcl_hash {\r\nif(false && req.http.X-Varnish-Cache-Url) {\r\nhash_data(req.http.X-Varnish-Cache-Url);\r\n} else {\r\nhash_data(req.url);\r\n}\r\nif (req.http.Host) {\r\nhash_data(req.http.Host);\r\n} else {\r\nhash_data(server.ip);\r\n}\r\nhash_data(req.http.Ssl-Offloaded);\r\nif (req.http.X-Normalized-User-Agent) {\r\nhash_data(req.http.X-Normalized-User-Agent);\r\n}\r\nif (req.http.Accept-Encoding) {\r\nhash_data(req.http.Accept-Encoding);\r\n}\r\nif (req.http.X-Varnish-Store || req.http.X-Varnish-Currency) {\r\nhash_data(\"s=\" + req.http.X-Varnish-Store + \"&c=\" + req.http.X-Varnish-Currency);\r\n}\r\nif (req.http.X-Varnish-Esi-Access == \"private\" &&\r\nreq.http.Cookie ~ \"frontend=\") {\r\nhash_data(regsub(req.http.Cookie, \"^.*?frontend=([^;]*);*.*$\", \"\\1\"));\r\n}\r\nif (req.http.X-Varnish-Esi-Access == \"customer_group\" &&\r\nreq.http.Cookie ~ \"customer_group=\") {\r\nhash_data(regsub(req.http.Cookie, \"^.*?customer_group=([^;]*);*.*$\", \"\\1\"));\r\n}\r\nreturn (hash);\r\n}\r\nsub vcl_hit {\r\n}\r\nsub vcl_fetch {\r\nset req.grace = 15s;\r\nset beresp.http.X-Varnish-Host = req.http.host;\r\nset beresp.http.X-Varnish-URL = req.url;\r\nif (req.url ~ \"^(/media/|/skin/|/js/|/)(?:(?:index|litespeed)\\.php/)?\") {\r\nunset beresp.http.Vary;\r\nset beresp.do_gzip = true;\r\nif (beresp.status != 200 && beresp.status != 404) {\r\nset beresp.ttl = 15s;\r\nreturn (hit_for_pass);\r\n} else {\r\nif (beresp.http.Set-Cookie) {\r\nset beresp.http.X-Varnish-Set-Cookie = beresp.http.Set-Cookie;\r\nunset beresp.http.Set-Cookie;\r\n}\r\nunset beresp.http.Cache-Control;\r\nunset beresp.http.Expires;\r\nunset beresp.http.Pragma;\r\nunset beresp.http.Cache;\r\nunset beresp.http.Age;\r\nif (beresp.http.X-Turpentine-Esi == \"1\") {\r\nset beresp.do_esi = true;\r\n}\r\nif (beresp.http.X-Turpentine-Cache == \"0\") {\r\nset beresp.ttl = 15s;\r\nreturn (hit_for_pass);\r\n} else {\r\nif (true &&\r\nbereq.url ~ \".*\\.(?:css|js|jpe?g|png|gif|ico|swf)(?=\\?|&|$)\") {\r\nset beresp.ttl = 28800s;\r\nset beresp.http.Cache-Control = \"max-age=28800\";\r\n} elseif (req.http.X-Varnish-Esi-Method) {\r\nif (req.http.X-Varnish-Esi-Access == \"private\" &&\r\nreq.http.Cookie ~ \"frontend=\") {\r\nset beresp.http.X-Varnish-Session = regsub(req.http.Cookie,\r\n\"^.*?frontend=([^;]*);*.*$\", \"\\1\");\r\n}\r\nif (req.http.X-Varnish-Esi-Method == \"ajax\" &&\r\nreq.http.X-Varnish-Esi-Access == \"public\") {\r\nset beresp.http.Cache-Control = \"max-age=\" + regsub(\r\nreq.url, \".*/ttl/(\\d+)/.*\", \"\\1\");\r\n}\r\nset beresp.ttl = std.duration(\r\nregsub(\r\nreq.url, \".*/ttl/(\\d+)/.*\", \"\\1s\"),\r\n300s);\r\nif (beresp.ttl == 0s) {\r\nset beresp.ttl = 15s;\r\nreturn (hit_for_pass);\r\n}\r\n} else {\r\nset beresp.ttl = 3600s;\r\n}\r\n}\r\n}\r\nreturn (deliver);\r\n}\r\n}\r\nsub vcl_deliver {\r\nif (req.http.X-Varnish-Faked-Session) {\r\nset resp.http.Set-Cookie = req.http.X-Varnish-Faked-Session +\r\n\"; expires=\" + resp.http.X-Varnish-Cookie-Expires + \"; path=/\";\r\nif (req.http.Host) {\r\nif (req.http.User-Agent ~ \"^(?:ApacheBench/.*|.*Googlebot.*|JoeDog/.*Siege.*|magespeedtest\\.com|Nexcessnet_Turpentine/.*|Baidu/.*|Bing/.*|Yandex/.*|Yahoo/.*)$\") {\r\nset resp.http.Set-Cookie = resp.http.Set-Cookie +\r\n\"; domain=\" + regsub(req.http.Host, \":\\d+$\", \"\");\r\n} else {\r\nif(req.http.Host ~ \"\") {\r\nset resp.http.Set-Cookie = resp.http.Set-Cookie +\r\n\"; domain=\";\r\n} else {\r\nset resp.http.Set-Cookie = resp.http.Set-Cookie +\r\n\"; domain=\" + regsub(req.http.Host, \":\\d+$\", \"\");\r\n}\r\n}\r\n}\r\nset resp.http.Set-Cookie = resp.http.Set-Cookie + \"; httponly\";\r\nunset resp.http.X-Varnish-Cookie-Expires;\r\n}\r\nif (req.http.X-Varnish-Esi-Method == \"ajax\" && req.http.X-Varnish-Esi-Access == \"private\") {\r\nset resp.http.Cache-Control = \"no-cache\";\r\n}\r\nif (false || client.ip ~ debug_acl) {\r\nset resp.http.X-Varnish-Hits = obj.hits;\r\nset resp.http.X-Varnish-Esi-Method = req.http.X-Varnish-Esi-Method;\r\nset resp.http.X-Varnish-Esi-Access = req.http.X-Varnish-Esi-Access;\r\nset resp.http.X-Varnish-Currency = req.http.X-Varnish-Currency;\r\nset resp.http.X-Varnish-Store = req.http.X-Varnish-Store;\r\n} else {\r\nunset resp.http.X-Varnish;\r\nunset resp.http.Via;\r\nunset resp.http.X-Powered-By;\r\nunset resp.http.Server;\r\nunset resp.http.X-Turpentine-Cache;\r\nunset resp.http.X-Turpentine-Esi;\r\nunset resp.http.X-Turpentine-Flush-Events;\r\nunset resp.http.X-Turpentine-Block;\r\nunset resp.http.X-Varnish-Session;\r\nunset resp.http.X-Varnish-Host;\r\nunset resp.http.X-Varnish-URL;\r\nunset resp.http.X-Varnish-Set-Cookie;\r\n}\r\n}\r\n\r\nThis is what's in the varnish_custom vcl\r\n\r\nsub vcl_recv {\r\n    if(req.http.User-Agent ~ \"iP(?:hone|ad|od)|BlackBerry|Palm|Googlebot-Mobile|Mobile|mobile|mobi|Windows Mobile|Safari Mobile|Android|Opera (?:Mini|Mobi)\") {\r\n        return(pipe);\r\n    }\r\n    \r\n    if(req.http.Host ~ \"test\\.americanlegacyfishing\\.com\") {\r\n        return(pipe);\r\n    }\r\n}\r\n\r\n"},"comment":{"url":"https://api.github.com/repos/nexcess/magento-turpentine/issues/comments/159387459","html_url":"https://github.com/nexcess/magento-turpentine/issues/1023#issuecomment-159387459","issue_url":"https://api.github.com/repos/nexcess/magento-turpentine/issues/1023","id":159387459,"user":{"login":"miguelbalparda","id":3997682,"avatar_url":"https://avatars.githubusercontent.com/u/3997682?v=3","gravatar_id":"","url":"https://api.github.com/users/miguelbalparda","html_url":"https://github.com/miguelbalparda","followers_url":"https://api.github.com/users/miguelbalparda/followers","following_url":"https://api.github.com/users/miguelbalparda/following{/other_user}","gists_url":"https://api.github.com/users/miguelbalparda/gists{/gist_id}","starred_url":"https://api.github.com/users/miguelbalparda/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/miguelbalparda/subscriptions","organizations_url":"https://api.github.com/users/miguelbalparda/orgs","repos_url":"https://api.github.com/users/miguelbalparda/repos","events_url":"https://api.github.com/users/miguelbalparda/events{/privacy}","received_events_url":"https://api.github.com/users/miguelbalparda/received_events","type":"User","site_admin":false},"created_at":"2015-11-24T19:55:23Z","updated_at":"2015-11-24T19:55:23Z","body":"I checked your log and I noted 2 things:\r\n1. You are using an ajax cart extension, so we can't determine if this is a problem with Turpentine or an incompatibility with your extension in particular.\r\n2. You are getting an error with a delete action and not an add action, not sure what this means.\r\nWhat I suggest is to test with a Magento without that extension and then start debugging to see where the error is happening. Also check this repository (issues, PR, documentation) for known Ajax issues."}}