Created attachment 668900 [details] server.log ovirt-engine-backend: server.log is flooded by apache messages :'[org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-6) Cookies: Invalid cookie. Value not a token or quoted value' server.log: *********** 2012-12-25 09:15:13,304 INFO [org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-3) Cookies: Invalid cookie. Value not a token or quoted value 2012-12-25 09:15:13,374 INFO [org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-13) Cookies: Invalid cookie. Value not a token or quoted value 2012-12-25 09:15:13,375 INFO [org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-6) Cookies: Invalid cookie. Value not a token or quoted value 2012-12-25 09:15:13,385 INFO [org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-1) Cookies: Invalid cookie. Value not a token or quoted value 2012-12-25 09:15:13,409 INFO [org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-10) Cookies: Invalid cookie. Value not a token or quoted value 2012-12-25 09:15:13,409 INFO [org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-4) Cookies: Invalid cookie. Value not a token or quoted value 2012-12-25 09:15:13,410 INFO [org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-3) Cookies: Invalid cookie. Value not a token or quoted value 2012-12-25 09:15:13,410 INFO [org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-11) Cookies: Invalid cookie. Value not a token or quoted value 2012-12-25 09:15:14,729 INFO [org.apache.tomcat.util.http.Cookies] (ajp-/127.0.0.1:8702-9) Cookies: Invalid cookie. Value not a token or quoted value
Yaniv Dary found this same issue some time ago with the reports application. He solved it adding the following to /etc/sysconfig/ovirt-engine as part of the reports setup: ENGINE_PROPERTIES=-Dorg.apache.tomcat.util.http.ServerCookie.ALLOW_HTTP_SEPARATORS_IN_V0=true Omri, do you have the reports application deployed in that environment? Does /etc/sysconfig/ovirt-engine contain this property? If it doesn't, can you add this manually and see if you still get the messages? If that solves the problem then we could add this property in the engine start script by default. However I would like to understand which cookie is malformed. Omri, would it be possible to get a dump of the traffic going to the 8702 port of the engine when this is happening?
Jasper just offered a possible cause to this issue on the reports side: " The problem may be caused by incorrect JBoss configuration and JRS gets freaked out by forward slashes. JBoss 7 sets the session cookie path wrapped in quotes, Firefox treats the quotes as part of the path itself so it never sends session cookie info in requests which causes a new session to created on each request. Can you please tell me what values do these configuration properties have in your JBoss? org.apache.tomcat.util.http.ServerCookie.FWD_SLASH_IS_SEPARATOR org.apache.catalina.STRICT_SERVLET_COMPLIANCE"
I looked and saw "STRICT_SERVLET_COMPLIANC" was changed to true by default due to: http://cve.mitre.org/cgi-bin/cvename.cgi?name=CVE-2007-5333 Yaniv
Also see thread: https://community.jboss.org/thread/205264 Yaniv
(In reply to comment #3) > Yaniv Dary found this same issue some time ago with the reports application. > He solved it adding the following to /etc/sysconfig/ovirt-engine as part of > the reports setup: > > ENGINE_PROPERTIES=-Dorg.apache.tomcat.util.http.ServerCookie. > ALLOW_HTTP_SEPARATORS_IN_V0=true > > Omri, do you have the reports application deployed in that environment? No reports installed, I saw it happens on both RHEVM 3.1 Build SI25.2 And RHEVM 3.2 Build SF2.1. > Does /etc/sysconfig/ovirt-engine contain this property? It's Not there by default. > If it doesn't, can you add this manually and see if you still get the messages? After adding the property - it stopped the flood of messages in server.log > If that solves the problem then we could add this property in the engine > start script by default. However I would like to understand which cookie is > malformed. Omri, would it be possible to get a dump of the traffic going to > the 8702 port of the engine when this is happening? attached tcpdump
Created attachment 670936 [details] tcpdump
Looking at the dump I see some requests where the cookie header is like this (package number 66 in the dump): JSESSIONID=LXih-by6n9nT7zTAPFu3kEqH; s_vi=[CS]v1|265EC9D5851D2BB2-6000010C800014AA[CE]; ... (There are many other cookies in the request, but I omitted them) The JSESSIONID cookie is expected and normal, and doesn't contain any problematic character. But the s_vi cookie is not expected, and it does contain characters that JBoss doesn't allow by default in cookies, in particular the square brackets, thus the message in the log. Why is your browser sending those cookies to the engine? It looks like those cookies are used by a product from Adobe called "Omniture SiteCatalyst", so I guess that in the past you used the same browser to connect to a server with the same host name or IP address and with that product installed, thus the browser is sending the cookies back. I would suggest to double check this connecting to the engine after cleaning the cookies in the browser. If the warning goes away then I think that it is safe to leave things as they are, without modifying anything in the engine.
Also got a reply from jasper on this: "I believe I have found the problem cookie. According to RFC 6265, which defines the cookie standard, there are certain special characters not allowed in the cookie value. They are white-space characters, double quote, comma, semicolon and backslash. In the cookies.txt file you attached to the case there are three cookies coming from JRS: dbotzer-installation.qa.lab.tlv.redhat.com FALSE /rhevm-reports/ FALSE 1355997920 userLocale en_US dbotzer-installation.qa.lab.tlv.redhat.com FALSE /rhevm-reports/ FALSE 1355997920 userTimezone Asia/Jerusalem dbotzer-installation.qa.lab.tlv.redhat.com FALSE /rhevm-reports TRUE 0 JSESSIONID Qwxn8GXRZi9RiCVUr3qoxOLZ and the cookie values are all within the specs. There are 18 other cookies coming from either www.redhat.com or .redhat.com. I'm not sure why these cookies are in your environment but they do not exist in our VM, which is why we don't see the INFO messages. The following cookie has invalid white-space characters, %20, which is hex for 'space.' .redhat.com TRUE / FALSE 0 s_ria flash%2011%7Csilverlight%20not%20detected The value translates to, "flash 11|silverlight not, detected," which has three invalid white-space characters. I'm quite certain that this is the one causing the messages to be generated." What do you think?
I must also add that also got "s_vi [CS]v1|276478C8851D3686-40000142E012B9DF[CE]" in the cookies. This doesn't recreate on the jasper side on a vm with rhev and reports.
I think that the jasper team analysis is correct, and probably the s_ria cookie is generated by the same software than the s_vi cookie. We can handle this in three different ways: 1. Do nothing, expecting that users will not be sending this cookies to their RHEV-M installations. 2. Add the ALLOW_HTTP_SEPARATORS_IN_V0 option by default (see comment #3) so that the cookies will be accepted without sending messages to the log. 3. Configure the logging subsystem so that it will suppress the log messages from the org.apache.tomcat.util.http.Cookies class.
BTW this cookie types are sent by by Adobe SiteCatalyst to anonymously track visitor activity in the red hat domain.
This is how to reproduce the issue (including the blank line and the line with only a dot): openssl s_client -connect f17.example.com:443 <<'.' GET / HTTP/1.1 Host: f17.example.com Connection: close Cookie: broken=[whatever] . Replace f17.example.com with the address of your engine.
The following patch changes the logging configuration so that the message informing about the problem with the cookies is discarded: http://gerrit.ovirt.org/10877
Setting to MODIFIED as was merged upstream prior to last rebase
3.2 has been released