Analyzing OWASP Mod Security Audit Log with R

Mod Security audit log file is organised in sections.  Each section starts on a new line and can be composed of multiple lines.  Sections are separated by a line specifying the transaction IDs and section code. A description of each section can be found here: https://www.feistyduck.com

 --38c0471f-A--  
 [04/Apr/2018:15:35:55 +0000] WsTw20sPICSQr9pUrF5lpQAAAAs x.x.x.x 46351 x.x.x.x 443  
 --38c0471f-B--  
 GET /sitemap.xml HTTP/1.1  
 Host: 155.198.29.141  
 Accept-Encoding: identity  

For performance issue, we decided to read the audit file line by line in R. This means that our algorithm acts pretty much as a “human” reader would. A set of functions “understand” the content of the current line given the information retrieved in the previous lines. For example, if the previous line was 

 --38c0471f-A-- 

1.a Check and extract the content of the Section header and the Audit Log Header (A)

 # Load Regular Expression Library  
 require('stringr')  
    
 # Returns true if line is an Audit Log Header  
 auditLogIsTransaction <- function(line){  
  return(str_detect(line, "--[:xdigit:]{8}-[ABCDEFGHIJKZ]--"))  
 }  
   
 # Returns The transaction ID from the Audit Log Header  
 auditLogGetTransactionId <- function(line){  
  return(str_extract(line, "[:xdigit:]{8}"))  
 }  
   
 # Returns The section type from the Audit Log Header  
 auditLogGetTransactionSection <- function(line){  
  return(gsub("-","",str_extract(line, "-([ABCDEFGHIJKZ])-")))  
 }  
   
 # Returns the Transaction date  
 auditLogGetTransactionDate <- function(line){  
  extract <- str_extract(line, "[0123][0-9]/(Jan|Feb|Mar|Apr|May|Jun|Jul|Aug|Sep|Oct|Nov|Dec)/20(17|18|19|20)")  
  extractDate <- as.Date(extract,"%d/%b/%Y")  
  return( extractDate )  
 }  
 # Returns the IP addresses as an array. (i.e. [IP Source, IP Destination])  
 auditLogGetIPAddressesAndPorts <- function(line){  
  return(str_extract_all(line, "[0-9]{1,3}\\.[0-9]{1,3}\\.[0-9]{1,3}\\.[0-9]{1,3}\\s[0-9]{2,5}"))  
 }  
   

 --38c0471f-A--  
 [04/Apr/2018:15:35:55 +0000] WsTw20sPICSQr9pUrF5lpQAAAAs 66.x.x.x 46351 x.x.x.x 443  
 --38c0471f-B--  
 GET /sitemap.xml HTTP/1.1  
 Host: 155.198.29.141  
 Accept-Encoding: identity  

1.b Check and extract OWASP Rule information in Section H

 --38c0471f-H--  
 Message:... [id "920350"] [rev "2"] [msg "Host header is a numeric IP address"] ... 
 Apache-Error: [file "apache2_util.c"] ... [client %s] ModSecurity: %s%s [uri "%s"]%s  
 Stopwatch: 1522856155328261 2511 (- - -)  
 Stopwatch2: 1522856155328261 2511; combined=1679,..., sr=122, sw=0, l=0, gc=0  
 Response-Body-Transformed: Dechunked  
 Producer: ModSecurity for Apache/2.9.1 (http://www.modsecurity.org/); OWASP_CRS/3.0.2.  
 Server: Apache  
 Engine-Mode: "ENABLED"

 # Returns true if contains a rule id  
 auditLogHasErrorCodeMessage <- function(line){  
  require('stringr')  
  return(str_detect(line, '\\[id "\\d{3,10}"\\]'))  
 }  
 # Returns the id of the rule  
 auditLogGetErrorCodeMessage <- function(line){  
  require('stringr')  
  return(str_extract(str_extract(line, '\\[id "[0-9]{3,10}"\\]'),"[0-9]{3,10}"))  
 }  

1.c Read *and make sense of* the current Line 

   
 processAuditLogLine <- function(fileLine, data){  
  # Create structured storage if absent  
  if(is.null(data)){  
   data <- data.frame(txId = NA, txSection = NA, txDate = NA, txSourceIp = NA, txSourceIpLocation = NA, txSourcePort = NA, txDestIp = NA, txDestPort = NA, txRule = NA )  
  }  
  # Check if line is transaction   
  if(auditLogIsTransaction(fileLine)){  
   # Retrieve Transaction Id  
   txId <- auditLogGetTransactionId(fileLine)  
   # Retrieve transaction Type  
   txSection <- auditLogGetTransactionSection(fileLine)  
   if(txSection == 'A'){  
    data <- rbind(data, data.frame(txId = txId, txSection = txSection, txDate = NA, txSourceIp = NA, txSourceIpLocation = NA, txSourcePort = NA, txDestIp = NA, txDestPort = NA, txRule = NA))  
   }else{  
    # retrive current data row  
    txRow <- dim(data)[1]  
    data[txRow,'txSection'] <- txSection   
   }  
     
  }else{  
    
   # retrive current data row  
   txRow <- dim(data)[1]  
   
   # Check line not empty  
   if(fileLine !=''){  
      
    # Retrieve current Section Type  
    currentSection <- data[txRow,'txSection']  
       # Check if section is for a new HTTP Request (A)  
    if(currentSection == 'A'){  
      # Retrieve Date  
      data[txRow,'txDate'] <- auditLogGetTransactionDate(fileLine)  
      # Retrieve IP addresses and ports  
      ipAddressesArr <- unlist(auditLogGetIPAddressesAndPorts(fileLine))  
      source <- unlist(strsplit(ipAddressesArr[1]," "))  
      dest <- unlist(strsplit(ipAddressesArr[2]," "))  
            # Store IP addesses and ports in data  
      data[txRow,'txSourceIp'] <- source[1]  
      data[txRow,'txSourcePort'] <- source[2]  
      data[txRow,'txDestIp'] <- dest[1]  
      data[txRow,'txDestPort'] <- dest[2]  
    }  
        # Check if section is giving information about the Rule (H)  
    if(currentSection == 'H'){  
           #   
     if(startsWith(fileLine, 'Message: ')){  
      data[txRow,'txRule'] <- auditLogGetErrorCodeMessage(fileLine)  
     }  
    }  
   }  
  }  
  return(data)  
 }  
   

1.d Read the file 

 processLogFile <- function(filepath, method) {  
  con = file(filepath, "r")  
  data <- NULL  
  while ( TRUE ) {  
   line = readLines(con, n = 1)  
   if ( length(line) == 0 ) {  
    break  
   }  
   # execute method on line   
   data <- method(line, data)  
  }  
  close(con)  
   
  return(data)  
 }  
   

 # File Location  
 pathAudit <- 'C:/Temp/Logs/modsec_audit_20181001.log'   
 # Parse/Read Audit Log  
 data <- processLogFile(pathAudit, processAuditLogLine)  
 # Display data  
 head(data, 9)  

 retrieveIPsLocations <- function(threatsData){  
  # Library  
  require('jsonlite')  
    
  # Find unique Ips  
  unIps <- unique(threatsData$txSourceIp)  
  countriesForIpsDataFrame <- data.frame(txSourceIp = unIps, txSourceCountry = rep(NA, length(unIps)))  
  # Using https://ipstack.com  
  API_Key <- "########################"  
  countriesForIpsDataFrame$txSourceCountry <- unlist(apply(countriesForIpsDataFrame, 1, FUN = function(x){  
   # API URL for SPECIFIC IP  
   URL <- paste("http://api.ipstack.com/",x[1],"?access_key=",API_Key, sep = "")  
   jsonObj <- fromJSON(URL)  
   if(is.null(jsonObj) || is.null(jsonObj$country_name))  
    return(NA)  
   else  
    return(jsonObj$country_name)  
  }))  
    
  threatsData <- merge(threatsData, countriesForIpsDataFrame, by='txSourceIp')  
  return(threatsData)  
 }  
   

3 Analyzing the Data

 mapThreats <- function(threathDataset){  
  require('rworldmap')  
  #Aggregate By countries  
  threathDataset <- threats %>% group_by(txSourceCountry) %>% summarise(ThreatsCount=n()) %>% arrange(desc(ThreatsCount))  
  spMapDF <- joinCountryData2Map(threathDataset, joinCode = "NAME", nameJoinColumn = "txSourceCountry")  
  mapCountryData( spMapDF, nameColumnToPlot="ThreatsCount" )  
 }  

 # Visualise threats count by country  
 mapThreats(threats)  

 # Filter for IP Rule   
 threats <- threats %>% filter(txRule!=920350)  
 # Visualise threats count by country  
 mapThreats(threats)  

3.b Analyzing the Type of attack

 barPlotModSecRules <- function(threatsDataset){  
  require('ggplot2')  
  rules <- as.data.frame(threats %>% group_by(txRule) %>% summarise(ThreatsCount=n()) %>% arrange(desc(ThreatsCount)))  
  rules$txRule <- as.factor(rules$txRule)  
  ggplot(data=rules[1:10,], aes(x=txRule, y=ThreatsCount)) +  
   geom_bar(stat="identity", width=0.5)  
 }  
 # Visualize rules in a Bar plot  
 barPlotModSecRules(threats)  

3.c Analyzing the chronology of attacks

Using our data.frame, we can visualize the chronology of attacks and search for seasonal patterns. In addition we can search for trends or stationarity.

 # Count blocked HTTP requests for each day in our dataset  
 dataAtHand <- threats %>% group_by(txDate) %>% summarise(count=n()) %>% arrange(txDate)  
 # Create dataset with all days between the first and last day of the log  
 allDates <-data.frame(txDate= seq(as.Date(unlist(head(dataAtHand,1)[1])), as.Date(unlist(tail(dataAtHand,1)[1])), by="days"))  
 # Merge data frame containing all the dates with the data frame containing the count.   
 datesData <- merge(allDates, dataAtHand , by="txDate" ,all.x=TRUE) %>% arrange(txDate)  
 # Set count equal to zero when no request for one day  
 datesData[is.na(datesData$count),'count']<- 0  
   
 # Plot time series  
 par(mar=c(8,4.1,4.1,2.1))  
 plot(ts(datesData$count), axes=F, ylab="Warnings",xlab="")  
 title(xlab="Time", line=6, cex.lab=1.2)  
 labelsIndexes <-seq(1,length(datesData$txDate), by=30)  
 axis(1, at = labelsIndexes, labels = datesData$txDate[labelsIndexes], las=3)  
 axis(2)  
   

The code above returns the following time series plot:

No clear seasonality and trend could be found be inspecting the graph visually.  Further test statistics could be used to assess whether either seasonality or trend effect are present.

4. Conclusion