Hi >-----Original Message----- >From: pet...@gmx-ist-cool.de [mailto:pet...@gmx-ist-cool.de] >Sent: 28. toukokuuta 2009 18:12 >To: haproxy@formilux.org >Subject: Re: An IE bug and HAproxy? >I run into a similar problem, when using haproxy version greater 1.3.16 in conjunction with ssl (stunnel). After a >post no data was sent back to IE. Using firefox everything is fine. > >I also noticed that the order of the entries on the statistic's page changed with the new versions.
I have hopefully some additional info. I managed to collect data with Wireshark on the same computer HAproxy and Stunnel is installed. Here's the data between the browser (xxx.xxx.xxx.xxx) and Stunnel (10.1.1.111): "4991","12:00:16.127353","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TCP" ,"4191 > https [ACK] Seq=1 Ack=1 Win=17520 Len=0" "4992","12:00:16.129101","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Client Hello, [Unreassembled Packet] " "4993","12:00:16.129110","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TCP" ,"https > 4191 [ACK] Seq=1 Ack=103 Win=5840 Len=0" "4994","12:00:16.129254","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TLSv 1","Server Hello, [Packet size limited during capture]" "4995","12:00:16.144093","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Change Cipher Spec, Encrypted Handshake Message, [Unreassembled Packet] " "4996","12:00:16.154336","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Application Data, [Unreassembled Packet] " "4997","12:00:16.154344","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TCP" ,"https > 4191 [ACK] Seq=123 Ack=1272 Win=7882 Len=0" "5003","12:00:16.159832","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Application Data, [Unreassembled Packet] " "5004","12:00:16.165080","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Ignored Unknown Record, [Packet size limited during capture]" "5005","12:00:16.165086","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TCP" ,"https > 4191 [ACK] Seq=123 Ack=4192 Win=13140 Len=0" "5006","12:00:16.173575","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Ignored Unknown Record, [Packet size limited during capture]" "5007","12:00:16.178821","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Ignored Unknown Record, [Packet size limited during capture]" "5008","12:00:16.178827","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TCP" ,"https > 4191 [ACK] Seq=123 Ack=7112 Win=18980 Len=0" "5009","12:00:16.184443","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Ignored Unknown Record, [Packet size limited during capture]" "5010","12:00:16.189565","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Ignored Unknown Record, [Packet size limited during capture]" "5011","12:00:16.189571","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TCP" ,"https > 4191 [ACK] Seq=123 Ack=10032 Win=24820 Len=0" "5012","12:00:16.194812","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Ignored Unknown Record, [Packet size limited during capture]" "5013","12:00:16.200184","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Ignored Unknown Record, [Packet size limited during capture]" "5014","12:00:16.200190","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TCP" ,"https > 4191 [ACK] Seq=123 Ack=12952 Win=30660 Len=0" "5015","12:00:16.205556","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Encrypted Alert, [Unreassembled Packet] " "5016","12:00:16.208180","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TLSv 1","Ignored Unknown Record, [Packet size limited during capture]" "5017","12:00:16.208185","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TCP" ,"https > 4191 [ACK] Seq=123 Ack=15258 Win=33580 Len=0" "23637","12:01:17.141752","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TLS v1","Application Data, [Unreassembled Packet] " "23641","12:01:17.141894","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TLS v1","Application Data, [Unreassembled Packet] " "23642","12:01:17.141977","10.1.1.111","https","xxx.xxx.xxx.xxx","4191","TLS v1","Ignored Unknown Record, [Packet size limited during capture]" "23650","12:01:17.162884","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TCP ","4191 > https [ACK] Seq=15258 Ack=1898 Win=17520 Len=0" "23653","12:01:17.163960","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TCP ","4191 > https [ACK] Seq=15258 Ack=2116 Win=17303 Len=0" "23654","12:01:17.164606","xxx.xxx.xxx.xxx","4191","10.1.1.111","https","TCP ","4191 > https [RST, ACK] Seq=15258 Ack=2116 Win=0 Len=0" and here the data between HAproxy (10.1.1.200) and the web server (10.1.1.222): "4998","12:00:16.154462","10.1.1.200","53757","10.1.1.222","http","TCP","537 57 > http [SYN] Seq=0 Win=5840 Len=0 MSS=1460 TSV=3515036725 TSER=0 WS=0" "4999","12:00:16.154586","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [SYN, ACK] Seq=0 Ack=1 Win=5792 Len=0 MSS=1460 TSV=445520735 TSER=3515036725 WS=2" "5000","12:00:16.154604","10.1.1.200","53757","10.1.1.222","http","TCP","537 57 > http [ACK] Seq=1 Ack=1 Win=5840 Len=0 TSV=3515036725 TSER=445520735" "5001","12:00:16.154616","10.1.1.200","53757","10.1.1.222","http","HTTP","PO ST /amd/p/salespeople/7cc2ph [Packet size limited during capture]" "5002","12:00:16.154960","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=1083 Win=7956 Len=0 TSV=445520736 TSER=3515036725" "5018","12:00:16.208350","10.1.1.200","53757","10.1.1.222","http","HTTP","Co ntinuation or non-HTTP traffic[Packet size limited during capture]" "5019","12:00:16.208356","10.1.1.200","53757","10.1.1.222","http","HTTP","Co ntinuation or non-HTTP traffic[Packet size limited during capture]" "5020","12:00:16.208361","10.1.1.200","53757","10.1.1.222","http","HTTP","Co ntinuation or non-HTTP traffic[Packet size limited during capture]" "5022","12:00:16.208804","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=2531 Win=10852 Len=0 TSV=445520790 TSER=3515036730" "5023","12:00:16.208813","10.1.1.200","53757","10.1.1.222","http","HTTP","Co ntinuation or non-HTTP traffic[Packet size limited during capture]" "5024","12:00:16.208816","10.1.1.200","53757","10.1.1.222","http","HTTP","Co ntinuation or non-HTTP traffic[Packet size limited during capture]" "5025","12:00:16.208819","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=3979 Win=13748 Len=0 TSV=445520790 TSER=3515036730" "5026","12:00:16.208824","10.1.1.200","53757","10.1.1.222","http","HTTP","Co ntinuation or non-HTTP traffic[Packet size limited during capture]" "5027","12:00:16.208828","10.1.1.200","53757","10.1.1.222","http","HTTP","Co ntinuation or non-HTTP traffic[Packet size limited during capture]" "5028","12:00:16.208930","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=5427 Win=16644 Len=0 TSV=445520790 TSER=3515036730" "5029","12:00:16.208936","10.1.1.200","53757","10.1.1.222","http","HTTP","Co ntinuation or non-HTTP traffic[Packet size limited during capture]" "5030","12:00:16.208939","10.1.1.200","53757","10.1.1.222","http","HTTP","Co ntinuation or non-HTTP traffic[Packet size limited during capture]" "5034","12:00:16.209180","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=6875 Win=19540 Len=0 TSV=445520790 TSER=3515036730" "5035","12:00:16.209304","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=8323 Win=22436 Len=0 TSV=445520790 TSER=3515036730" "5036","12:00:16.209429","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=9771 Win=25332 Len=0 TSV=445520790 TSER=3515036730" "5037","12:00:16.209554","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=11219 Win=28228 Len=0 TSV=445520790 TSER=3515036730" "5038","12:00:16.209679","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=12667 Win=31124 Len=0 TSV=445520791 TSER=3515036730" "5039","12:00:16.209804","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=14115 Win=34020 Len=0 TSV=445520791 TSER=3515036730" "23634","12:01:17.141570","10.1.1.222","http","10.1.1.200","53757","HTTP","H TTP/1.1 500 Internal Server E [Packet size limited during capture]" "23635","12:01:17.141581","10.1.1.200","53757","10.1.1.222","http","TCP","53 757 > http [ACK] Seq=14115 Ack=295 Win=6432 Len=0 TSV=3515042823 TSER=445581732" "23636","12:01:17.141691","10.1.1.200","53757","10.1.1.222","http","HTTP","C ontinuation or non-HTTP traffic[Packet size limited during capture]" "23638","12:01:17.141786","10.1.1.222","http","10.1.1.200","53757","HTTP","C ontinuation or non-HTTP traffic[Packet size limited during capture]" "23639","12:01:17.141793","10.1.1.222","http","10.1.1.200","53757","HTTP","C ontinuation or non-HTTP traffic[Packet size limited during capture]" "23640","12:01:17.141799","10.1.1.200","53757","10.1.1.222","http","TCP","53 757 > http [ACK] Seq=15048 Ack=1929 Win=11584 Len=0 TSV=3515042823 TSER=445581732" "23643","12:01:17.142000","10.1.1.200","53757","10.1.1.222","http","TCP","53 757 > http [FIN, ACK] Seq=15048 Ack=1929 Win=11584 Len=0 TSV=3515042823 TSER=445581732" "23644","12:01:17.142002","10.1.1.222","http","10.1.1.200","53757","TCP","ht tp > 53757 [RST] Seq=295 Win=0 Len=0" "23645","12:01:17.142007","10.1.1.222","http","10.1.1.200","53757","TCP","ht tp > 53757 [RST] Seq=1929 Win=0 Len=0" "23646","12:01:17.142215","10.1.1.222","http","10.1.1.200","53757","TCP","ht tp > 53757 [RST] Seq=1929 Win=0 Len=0" As the first set of data is encrypted you can only study the time stamps. But as both samples are collected in the same machine, the relative time stamps are valid. It seems to me - and I am no network expert in analyzing network traffic - that Stunnel sends the last [ACK] before the one minute delay at 12:00:16.208185 (packet 5017). After that the server sends multiple [ACK]s "5022","12:00:16.208804","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=2531 Win=10852 Len=0 TSV=445520790 TSER=3515036730" "5025","12:00:16.208819","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=3979 Win=13748 Len=0 TSV=445520790 TSER=3515036730" "5028","12:00:16.208930","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=5427 Win=16644 Len=0 TSV=445520790 TSER=3515036730" "5034","12:00:16.209180","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=6875 Win=19540 Len=0 TSV=445520790 TSER=3515036730" "5035","12:00:16.209304","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=8323 Win=22436 Len=0 TSV=445520790 TSER=3515036730" "5036","12:00:16.209429","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=9771 Win=25332 Len=0 TSV=445520790 TSER=3515036730" "5037","12:00:16.209554","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=11219 Win=28228 Len=0 TSV=445520790 TSER=3515036730" "5038","12:00:16.209679","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=12667 Win=31124 Len=0 TSV=445520791 TSER=3515036730" "5039","12:00:16.209804","10.1.1.222","http","10.1.1.200","53757","TCP","htt p > 53757 [ACK] Seq=1 Ack=14115 Win=34020 Len=0 TSV=445520791 TSER=3515036730" none of which can be seen between Stunnel and the browser. Of course the problem could also be Stunnel? But a further piece of data points to HAproxy: one of the web servers is installed in the same machine as HAproxy and that specific server doesn't seem to suffer from this same problem. If the culprit was Stunnel I should imagine that there couldn't be any differences between servers as all the data it gets is from HAproxy. These computers have firewall (Shorewall), but firewalls were temporary not in use when this data was collected. And as the capture shows the ACKs send by the machine B hosting the web server were received on the computer A hosting HAproxy & Stunnel. This is admittedly a difficult bug to trace as IE works OK most of the time and so the problem is difficult to reproduce. It is also possible that this has nothing to do with IE and it has only been a coindicence that IE is affected. I am soon leaving for a trip for but will join the discussion when I am back. You all have a nice early summer.
