Incomplete but 2 logs for same transaction (libhtp: 0.5.x)

[Sachin-M-Desai]

When a server performs a 302 redirect, am seeing request and responses being treated as 2 different transactions.

Curl used to a perform a POST with some finite amount of data (in my setup 1000+ bytes work).

curl -X POST localhost:3000/WebGoat/login1 -d@somedata

• Trying 127.0.0.1:3000...
• TCP_NODELAY set
• Connected to localhost (127.0.0.1) port 3000 (#0)

POST /WebGoat/login1 HTTP/1.1
Host: localhost:3000
User-Agent: curl/7.68.0
Accept: /
Content-Length: 1417
Content-Type: application/x-www-form-urlencoded
Expect: 100-continue

• Mark bundle as not supporting multiuse
  < HTTP/1.1 100 Continue
  < Content-Length: 0
• We are completely uploaded and fine
• Mark bundle as not supporting multiuse
  < HTTP/1.1 302 Found
  < Connection: keep-alive
  < Set-Cookie: JSESSIONID=Pd4prqd4XB9lqkDl96LbacL2DlCxs_aAqudKCfzy; path=/WebGoat
  < X-XSS-Protection: 1; mode=block
  < X-Content-Type-Options: nosniff
  < X-Frame-Options: DENY
  < Location: http://localhost:3000/WebGoat/login
  < Content-Length: 0
  < Date: Tue, 01 Feb 2022 17:36:14 GMT
  <
• Connection #0 to host localhost left intact

Also, the redirect happened after 100-Continue, we should still not have gotten split sessions. Suricata logs here,

First log contains only request information -----------------------------------------------
{"timestamp":"2022-02-01T23:19:07.747041+0530","flow_id":1175502258919067,"in_iface":"lo","event_type":"http","src_ip":"127.0.0.1","src_port":47188,"dest_ip":"127.0.0.1","dest_port":3000,"proto":"TCP","tx_id":0,"http":{"hostname":"localhost","http_port":3000,"url":"/WebGoat/login1","http_user_agent":"curl/7.68.0","http_method":"POST","protocol":"HTTP/1.1","status":100,"length":0,"request_headers":[{"name":"Host","value":"localhost:3000"},{"name":"User-Agent","value":"curl/7.68.0"},{"name":"Accept","value":"/"},{"name":"Content-Length","value":"1417"},{"name":"Content-Type","value":"application/x-www-form-urlencoded"},{"name":"Expect","value":"100-continue"}],"response_headers":[{"name":"Content-Length","value":"0"}]}}

Second log contains only response information -----------------------------------------------
{"timestamp":"2022-02-01T23:19:07.754062+0530","flow_id":1175502258919067,"in_iface":"lo","event_type":"http","src_ip":"127.0.0.1","src_port":47188,"dest_ip":"127.0.0.1","dest_port":3000,"proto":"TCP","tx_id":1,"http":{"http_port":0,"url":"/libhtp::request_uri_not_seen","status":302,"redirect":"http://localhost:3000/WebGoat/login","length":0,"request_headers":[],"response_headers":[{"name":"Connection","value":"keep-alive"},{"name":"Set-Cookie","value":"JSESSIONID=raay5SraTiEQdyDg-auP7e-0D3mfAuSGuJefwPHF; path=/WebGoat"},{"name":"X-XSS-Protection","value":"1; mode=block"},{"name":"X-Content-Type-Options","value":"nosniff"},{"name":"X-Frame-Options","value":"DENY"},{"name":"Location","value":"http://localhost:3000/WebGoat/login"},{"name":"Content-Length","value":"0"},{"name":"Date","value":"Tue, 01 Feb 2022 17:49:07 GMT"}]}}

PCAP attached for the above transaction.
wg6-pcap.zip

Any help and inputs appreciated.

[catenacyber]

Thanks for this report.
If you want to help more, could you create a Suricata-verify test out of this ?

[catenacyber]

Could you test #351 ?

[Sachin-M-Desai]

Fix looks good. Thank you. Below is the log i now see.

{"timestamp":"2022-02-23T13:07:28.058210+0000","flow_id":1775922563793581,"in_iface":"lo","event_type":"http","src_ip":"127.0.0.1","src_port":33210,"dest_ip":"127.0.0.1","dest_port":3000,"proto":"6","tx_id":0,"http":{"hostname":"localhost","http_port":3000,"url":"/WebGoat/login1","http_user_agent":"curl/7.68.0","http_method":"POST","protocol":"HTTP/1.1","status":302,"redirect":"http://localhost:3000/WebGoat/login","length":0,"request_headers":[{"name":"Host","value":"localhost:3000"},{"name":"User-Agent","value":"curl/7.68.0"},{"name":"Accept","value":"*/*"},{"name":"Content-Length","value":"1417"},{"name":"Content-Type","value":"application/x-www-form-urlencoded"},{"name":"Expect","value":"100-continue"}],"response_headers":[{"name":"Connection","value":"keep-alive"},{"name":"Set-Cookie","value":"JSESSIONID=8DtreiCe0RbQqoZtVdzoBLFvc1WS1Hh562_0QaqR; path=/WebGoat"},{"name":"X-XSS-Protection","value":"1; mode=block"},{"name":"X-Content-Type-Options","value":"nosniff"},{"name":"X-Frame-Options","value":"DENY"},{"name":"Location","value":"http://localhost:3000/WebGoat/login"},{"name":"Content-Length","value":"0"},{"name":"Date","value":"Wed, 23 Feb 2022 13:07:28 GMT"}]}}

[catenacyber]

Thanks for testing

[Sachin-M-Desai]

Thanks for testing

Is there a release this fix will be targetted for? Would help if you could let me know the release and approx time

[catenacyber]

I think in will be in libhtp 0.5.40 which will be used by suricata 7.0rc1 and 6.0.5
cf https://redmine.openinfosecfoundation.org/issues/5146

[Sachin-M-Desai]

Thank you so much

[catenacyber]

Fixed by #351