Bug #109
closed
Inconsistent time stamps in http log file
Added by Will Metcalf over 14 years ago.
Updated almost 13 years ago.
Description
The http logging module now produces inconsistent timestamps the output below all comes from processing the same pcap.
09/21/09-13:48:50.866606 www.testmyids.com [**] / [**] Wget/1.11.4 [**] 192.168.2.3:50072 -> 82.165.50.118:80
09/21/09-13:48:50.723517 www.testmyids.com [**] / [**] Wget/1.11.4 [**] 192.168.2.3:50072 -> 82.165.50.118:80
09/21/09-13:48:50.582296 www.testmyids.com [**] / [**] Wget/1.11.4 [**] 192.168.2.3:50072 -> 82.165.50.118:80
09/21/09-13:48:50.723346 www.testmyids.com [**] / [**] Wget/1.11.4 [**] 192.168.2.3:50072 -> 82.165.50.118:80
09/21/09-13:48:50.582296 www.testmyids.com [**] / [**] Wget/1.11.4 [**] 192.168.2.3:50072 -> 82.165.50.118:80
09/21/09-13:48:50.723346 www.testmyids.com [**] / [**] Wget/1.11.4 [**] 192.168.2.3:50072 -> 82.165.50.118:80
Files
The bug seems not related to the http logging. As we have multiple threads, we decode more than one packet in parallel and assign a flow pointer to each packet, which is same for one session. When the packet comes to logging module, in the mean time the stream & app layer thread has already parsed the app layer request. As the packet has the same flow pointer assigned to it, the initial SYN or SYN/ACK packets also pass the app layer checks in the logging part and this causes the different time stamps to get printed.
I was thinking that it would be good to have a thread api, which allows us to pause/unpause a thread module e.g. Loghttp. The benefit of it will be that, we can pause the loghttp module until we have received a new request from the client. Upon receiving new request we unpause it and the request will be logged. After logging we can pause it again. Thus it will hopefully avoid the above inconsistency and improve performance to by avoiding unnecessary call to loghttp module.
- Due date changed from 03/10/2010 to 04/30/2010
- Assignee changed from OISF Dev to Victor Julien
- Target version changed from 0.8.2 to 0.9.0
This issue is related to handling & updating of the HtpState. We'll be reworking that the following weeks in a series of tasks.
- Target version changed from 0.9.0 to 0.9.1
- Target version changed from 0.9.1 to 0.9.2
- Due date changed from 04/30/2010 to 06/21/2010
- Priority changed from Normal to Low
- Target version changed from 0.9.2 to 0.9.3
- Target version changed from 0.9.3 to 1.0.1
Code for dealing better with state updates will go into 1.0.1.
- Due date deleted (
06/21/2010)
- Target version changed from 1.0.1 to TBD
Will be looking at this later, tired of targeting each time.
- Status changed from New to Assigned
- Assignee changed from Victor Julien to Peter Manev
Peter can you retest this issue?
After a 24 hr http.log has been inspected - this seems to be no longer an issue.
- Status changed from Assigned to Closed
- Target version changed from TBD to 1.1
- % Done changed from 0 to 100
- Related to Task #3056: Add test for #109: Inconsistent time stamps in http log file added
Also available in: Atom
PDF