One of the projects I'm working on requires logging a huge amount of information (basically, every function call). The problem is obviously that logging a lot of information has a few side-effects, notably high disk-use (both IO's and amount); tends to require lookup-tables if you're trying to keep things small (i.e. an "integer to page" conversion, etc.); often isn't atomic, that is, concurrency can often become a high target-factor for threaded logging.
To fix some (most) of this, I've worked up a binary encoding for our logs. Basically, it allows us to store a huge amount of information in a tight format, and also allows us to do so atomically and without any concurrency issues. As a result, we can have high-performance logging that doesn't bog anything down. It has a small drawback: encoding of names and some values are "lossy", that is to say, we don't take the entire thing into account.
The specification is a notepad document, which is below:
HEADBYTE (1) 00000001 - IP Version 00000010 - Page Name Supplied (1 if supplied) 01111100 - Parameter Count (Up to 32) 10000000 - Always 0, indicates "V1", if 1 then there's another headbyte for the next version IPBYTES (4 or 16) If IP Version = 0 Then 4 bytes (IPv4) Else 16 bytes (IPv6) DATETIME (8) Unix EPOCH Time in UTC USERID (5) 00000011 - User Type 4 bytes: Integer user ID PAGENAME (0 or 16) If Page Name = 0 Then 0 bytes (not supplied) Else 16 bytes for MD5 hash of URL + Folder + Page name FUNCTION NAME (16) 16 bytes for MD5 hash of Namespace + Module + Function name PARAMETERS (0 or *) If Parameter Count = 0 Then 0 bytes (not supplied) Else Parameters PARAMETER (<= 37) 1-byte for config: PARAMETER CONFIG 00000001 - 0 = Ref, 1 = Val 00001110 - Type: 0 = Non-numeric type, # = 2^(n - 1) size bytes 00010000 - Type Extension: If Type is non-numeric, 1 indicates data is string, 0 indicates custom class If Type is numeric, then 1 = Signed, 0 = Unsigned 10000000 - Always 0, indicates "V1", if 1 then there's another byte(s) for the next version 16 bytes for MD5 hash of parameter name If Type > 0 Then # bytes of actual numeric value Else If Type Extension = 1 Then 4 bytes for string length Else 16 bytes for MD5 hash of parameter type name (Full type name)
We can encode most of our data in less than 500 bytes, and much of it can be encoded in less than 200 bytes. By using the MD5 hash of the names / values, we can guarantee that there is not lookup or contention over storing them to any sort of "persistent" format, and it means we can build the lookup-table on-the-fly, so-to-speak. (We can store name + hash in the database, but it's no longer required for the logger to do it's job. We can fill it on a regular basis.) We use an MD5 hash for the speed, and the fact that, realistically, there are so few collisions on my use-case that it's not a big deal. Close counts, here.
An example (hexadecimal) log format might look like the following:
0f000000000000000000000000000000 01000001662b4bf83801000000c0c694 689b671598d0809e2935e7ccf4b6fa5c dcf6485054f1bcd699050864f2d505a5 0691680602baa24206181b31ceb3c201 011029a5b77a07118ffbdbecfac18b73 f7c50000000100b05a9ad34ddf60cadf 2ba9dac8fa3a345592700a1f3b26e424 bc7fe95e50f703
Which, once line-breaks are stripped, can be decoded into the resulting type structure:
type MD5Hash = byte []
type Header =
{ IPV6 : bool
PageNameSupplied : bool
ParameterCount : byte }
type IP =
| V4 of System.Net.IPAddress
| V6 of System.Net.IPAddress
type UserType =
| Client
| Vendor
| Admin
type DateTime = uint64
type UserId = UserType * uint32
type Number =
| Byte of byte
| SByte of sbyte
| UInt16 of uint16
| Int16 of int16
| UInt32 of uint32
| Int32 of int32
| UInt64 of uint64
| Int64 of int64
type ParameterValue =
| CustomClass of MD5Hash
| String of int
| Numeric of Number
type Parameter =
{ ValueType : bool
ParameterName : MD5Hash
ParameterValue : ParameterValue }
type LogMessage =
{ IP : IP
DateTime : DateTime
UserId : UserId
PageName : MD5Hash option
FunctionName : MD5Hash
Parameters : Parameter list }
To encode and decode we have some utility functions:
let md5Hash (str : string) : MD5Hash =
use md5 = System.Security.Cryptography.MD5.Create()
str
|> System.Text.Encoding.UTF8.GetBytes
|> md5.ComputeHash
let byteToUserType =
function
| 0b00000000uy -> UserType.Client
| 0b00000001uy -> UserType.Vendor
| 0b00000011uy -> UserType.Admin
| _ -> failwith "Invalid User Type"
let userTypeToByte =
function
| UserType.Client -> 0b00000000uy
| UserType.Vendor -> 0b00000001uy
| UserType.Admin -> 0b00000011uy
let byteArrayToByte =
function
| [|b1|] -> b1
| _ -> failwith "Byte may only have a single element byte-array"
let byteArrayToSByte =
function
| [|b1|] -> b1 |> sbyte
| _ -> failwith "SByte may only have a single element byte-array"
let byteArrayToUInt16 =
function
| [|b1; b2|] -> (b1 |> uint16) <<< 8 ||| (b2 |> uint16)
| _ -> failwith "UInt16 may only have a 2 element byte-array"
let byteArrayToInt16 =
function
| [|b1; b2|] -> (b1 |> int16) <<< 8 ||| (b2 |> int16)
| _ -> failwith "Int16 may only have a 2 element byte-array"
let byteArrayToUInt32 =
function
| [|b1; b2; b3; b4|] -> (b1 |> uint32) <<< 24 ||| (b2 |> uint32) <<< 16 ||| (b3 |> uint32) <<< 8 ||| (b4 |> uint32)
| _ -> failwith "UInt32 may only have a 4 element byte-array"
let byteArrayToInt32 =
function
| [|b1; b2; b3; b4|] -> (b1 |> int32) <<< 24 ||| (b2 |> int32) <<< 16 ||| (b3 |> int32) <<< 8 ||| (b4 |> int32)
| _ -> failwith "Int32 may only have a 4 element byte-array"
let byteArrayToUInt64 =
function
| [|b1; b2; b3; b4; b5; b6; b7; b8|] -> (b1 |> uint64) <<< 54 ||| (b2 |> uint64) <<< 48||| (b3 |> uint64) <<< 40 ||| (b4 |> uint64) <<< 32 ||| (b5 |> uint64) <<< 24 ||| (b6 |> uint64) <<< 16 ||| (b7 |> uint64) <<< 8 ||| (b8 |> uint64)
| _ -> failwith "UInt64 may only have a 8 element byte-array"
let byteArrayToInt64 =
function
| [|b1; b2; b3; b4; b5; b6; b7; b8|] -> (b1 |> int64) <<< 54 ||| (b2 |> int64) <<< 48||| (b3 |> int64) <<< 40 ||| (b4 |> int64) <<< 32 ||| (b5 |> int64) <<< 24 ||| (b6 |> int64) <<< 16 ||| (b7 |> int64) <<< 8 ||| (b8 |> int64)
| _ -> failwith "Int64 may only have a 8 element byte-array"
let byteArrayToNumber signature (bytes : byte []) =
match bytes, signature with
| [|b1|], false -> bytes |> byteArrayToByte |> Byte
| [|b1|], true -> bytes |> byteArrayToSByte |> SByte
| [|b1; b2|], false -> bytes |> byteArrayToUInt16 |> UInt16
| [|b1; b2|], true -> bytes |> byteArrayToInt16 |> Int16
| [|b1; b2; b3; b4|], false -> bytes |> byteArrayToUInt32 |> UInt32
| [|b1; b2; b3; b4|], true -> bytes |> byteArrayToInt32 |> Int32
| [|b1; b2; b3; b4; b5; b6; b7; b8|], false -> bytes |> byteArrayToUInt64 |> UInt64
| [|b1; b2; b3; b4; b5; b6; b7; b8|], true -> bytes |> byteArrayToInt64 |> Int64
| _ -> failwith "Number must have a 1, 2, 4, or 8 element byte-array"
let byteToByteArray n = [|n|]
let sbyteToByteArray n = [|n |> byte|]
let uint16ToByteArray n = [|(n >>> 8) |> byte; (n) |> byte|]
let int16ToByteArray n = [|(n >>> 8) |> byte; (n) |> byte|]
let uint32ToByteArray n = [|(n >>> 24) |> byte; (n >>> 16) |> byte; (n >>> 8) |> byte; (n) |> byte|]
let int32ToByteArray n = [|(n >>> 24) |> byte; (n >>> 16) |> byte; (n >>> 8) |> byte; (n) |> byte|]
let uint64ToByteArray n = [|(n >>> 56) |> byte; (n >>> 48) |> byte; (n >>> 40) |> byte; (n >>> 32) |> byte; (n >>> 24) |> byte; (n >>> 16) |> byte; (n >>> 8) |> byte; (n) |> byte|]
let int64ToByteArray n = [|(n >>> 56) |> byte; (n >>> 48) |> byte; (n >>> 40) |> byte; (n >>> 32) |> byte; (n >>> 24) |> byte; (n >>> 16) |> byte; (n >>> 8) |> byte; (n) |> byte|]
let numberToByteArray =
function
| Byte n -> false, (n |> byteToByteArray)
| SByte n -> true, (n |> sbyteToByteArray)
| UInt16 n -> false, (n |> uint16ToByteArray)
| Int16 n -> true, (n |> int16ToByteArray)
| UInt32 n -> false, (n |> uint32ToByteArray)
| Int32 n -> true, (n |> int32ToByteArray)
| UInt64 n -> false, (n |> uint64ToByteArray)
| Int64 n -> true, (n |> int64ToByteArray)
Then, we finally get to the heart of the encoding and decoding:
let readLogMessage (bytes : byte []) : Result<byte [] * LogMessage, string> =
let readLogHeader (bytes : byte []) : Result<byte [] * Header, string> =
let headerByte = bytes.[0]
if (headerByte &&& 0b10000000uy) > 0uy then
Error "Only V1 is supported."
else
let remBytes = bytes.[1..]
let ipVersion = headerByte &&& 0b00000001uy > 0uy
let pageNameSupplied = headerByte &&& 0b00000010uy > 0uy
let parameterCount = headerByte &&& 0b01111100uy >>> 2
(remBytes, { Header.IPV6 = ipVersion; PageNameSupplied = pageNameSupplied; ParameterCount = parameterCount }) |> Ok
match bytes |> readLogHeader with
| Ok (bytes, header) ->
let bytes, ip =
match header.IPV6 with
| false -> bytes.[4..], V4 (bytes.[..3] |> System.Net.IPAddress)
| true -> bytes.[16..], V6 (bytes.[..15] |> System.Net.IPAddress)
let bytes, datetime = bytes.[8..], bytes.[..7]
let bytes, userType = bytes.[1..], ((bytes.[0] &&& 0b00000011uy) |> byteToUserType)
let bytes, userid = bytes.[4..], bytes.[..3]
let bytes, pageName =
match header.PageNameSupplied with
| false -> bytes, None
| true -> bytes.[16..], (bytes.[..15] |> Some)
let bytes, functionName = bytes.[16..], bytes.[..15]
let rec readParameters (bytes : byte []) ps rem =
match rem with
| 0 -> ps
| r ->
let bytes, head = bytes.[1..], bytes.[0]
let valueType = head &&& 0b00000001uy > 0uy
let typeVal = head &&& 0b00001110uy >>> 1
let typeExt = head &&& 0b00010000uy > 0uy
let bytes, parameterName = bytes.[16..], bytes.[..15]
let bytes, value =
match typeVal, typeExt with
| 0uy, false -> bytes.[16..], CustomClass (bytes.[..15])
| 0uy, true -> bytes.[4..], String (bytes.[..3] |> byteArrayToInt32)
| i, signed -> bytes.[i |> int..], Numeric (bytes.[..(pown 2 ((i |> int) - 1)) - 1] |> byteArrayToNumber signed)
let ps = { ValueType = valueType; ParameterName = parameterName; ParameterValue = value } :: ps
readParameters bytes ps (r - 1)
Ok (bytes,
{ IP = ip
DateTime = datetime |> byteArrayToUInt64
UserId = userType, (userid |> byteArrayToUInt32)
PageName = pageName
FunctionName = functionName
Parameters = readParameters bytes [] (header.ParameterCount |> int) |> List.rev })
| Error e -> Error e
let writeLogMessage (msg : LogMessage) : Result<byte [], string> =
let headerByte = match msg.IP with | V4 _ -> 0b00000000uy | V6 _ -> 0b00000001uy
let headerByte = headerByte ||| match msg.PageName with | Some _ -> 0b00000010uy | None -> 0b00000000uy
let headerByte = headerByte ||| ((msg.Parameters.Length <<< 3) |> byte >>> 1)
let result = [|headerByte|]
let result =
match msg.IP with
| V4 ip -> ip.GetAddressBytes()
| V6 ip -> ip.GetAddressBytes()
|> Array.append result
let result = msg.DateTime |> uint64ToByteArray |> Array.append result
let result =
let t, id = msg.UserId
id |> uint32ToByteArray |> Array.append [|0uy ||| (t |> userTypeToByte)|] |> Array.append result
let result =
match msg.PageName with
| Some h -> h
| None -> [| |]
|> Array.append result
let result = msg.FunctionName |> Array.append result
let rec writeParameters (bytes : byte []) ps =
match ps with
| [] -> bytes
| head::ps ->
let headByte = 0uy
let headByte = headByte ||| if head.ValueType then 0b00000001uy else 0b00000000uy
let addHeadByte, data =
match head.ParameterValue with
| CustomClass hash -> 0b00000000uy, hash
| String length -> 0b00010000uy, (length |> int32ToByteArray)
| Numeric n ->
let signed, bytes = n |> numberToByteArray
(if signed then 0b00010000uy else 0b00000000uy) ||| ((log (bytes.Length |> float) / log 2. + 1.) |> byte <<< 1), bytes
let headByte = headByte ||| addHeadByte
let result = [|headByte|]
let result = head.ParameterName |> Array.append result
let result = data |> Array.append result
writeParameters (result |> Array.append bytes) ps
msg.Parameters
|> writeParameters [| |]
|> Array.append result
|> Ok
And we can verify the whole thing with a simple script:
let input = [| //0b00001110uy // IPv4 0b00001111uy // IPv6 //0b01111111uy; 0b00000000uy; 0b00000000uy; 0b00000001uy // IPv4 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000001uy // IPv6 0b00000000uy; 0b00000000uy; 0b00000001uy; 0b01100110uy; 0b00101011uy; 0b01001011uy; 0b11111000uy; 0b00111000uy // DateTime Stamp 0b00000001uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b11000000uy // User ID 0b11000110uy; 0b10010100uy; 0b01101000uy; 0b10011011uy; 0b01100111uy; 0b00010101uy; 0b10011000uy; 0b11010000uy; 0b10000000uy; 0b10011110uy; 0b00101001uy; 0b00110101uy; 0b11100111uy; 0b11001100uy; 0b11110100uy; 0b10110110uy // Page Name 0b11111010uy; 0b01011100uy; 0b11011100uy; 0b11110110uy; 0b01001000uy; 0b01010000uy; 0b01010100uy; 0b11110001uy; 0b10111100uy; 0b11010110uy; 0b10011001uy; 0b00000101uy; 0b00001000uy; 0b01100100uy; 0b11110010uy; 0b11010101uy // Function Name 0b00000101uy; 0b10100101uy; 0b00000110uy; 0b10010001uy; 0b01101000uy; 0b00000110uy; 0b00000010uy; 0b10111010uy; 0b10100010uy; 0b01000010uy; 0b00000110uy; 0b00011000uy; 0b00011011uy; 0b00110001uy; 0b11001110uy; 0b10110011uy; 0b11000010uy; 0b00000001uy; 0b00000001uy // Parameter 1 0b00010000uy; 0b00101001uy; 0b10100101uy; 0b10110111uy; 0b01111010uy; 0b00000111uy; 0b00010001uy; 0b10001111uy; 0b11111011uy; 0b11011011uy; 0b11101100uy; 0b11111010uy; 0b11000001uy; 0b10001011uy; 0b01110011uy; 0b11110111uy; 0b11000101uy; 0b00000000uy; 0b00000000uy; 0b00000000uy; 0b00000001uy // Parameter 2 0b00000000uy; 0b10110000uy; 0b01011010uy; 0b10011010uy; 0b11010011uy; 0b01001101uy; 0b11011111uy; 0b01100000uy; 0b11001010uy; 0b11011111uy; 0b00101011uy; 0b10101001uy; 0b11011010uy; 0b11001000uy; 0b11111010uy; 0b00111010uy; 0b00110100uy; 0b01010101uy; 0b10010010uy; 0b01110000uy; 0b00001010uy; 0b00011111uy; 0b00111011uy; 0b00100110uy; 0b11100100uy; 0b00100100uy; 0b10111100uy; 0b01111111uy; 0b11101001uy; 0b01011110uy; 0b01010000uy; 0b11110111uy; 0b00000011uy // Parameter 3 |] let outMessage = readLogMessage input let message = { //IP = "127.0.0.1" |> System.Net.IPAddress.Parse |> V4 // IPv4 IP = "::1" |> System.Net.IPAddress.Parse |> V6 // IPv6 DateTime = System.DateTimeOffset(2018, 9, 30, 16, 24, 51, System.TimeSpan()).ToUnixTimeMilliseconds() |> uint64 UserId = UserType.Vendor, 192u PageName = "Dir/Page.aspx" |> md5Hash |> Some FunctionName = "Page_Load" |> md5Hash Parameters = [{ ValueType = true ParameterName = "Parameter 1" |> md5Hash ParameterValue = 257us |> UInt16 |> Numeric } { ValueType = false ParameterName = "Parameter 2" |> md5Hash ParameterValue = 1 |> String } { ValueType = false ParameterName = "Parameter 3" |> md5Hash ParameterValue = "Class Type" |> md5Hash |> CustomClass } ] } let output = writeLogMessage message input |> Array.iter (printf "%02x") printfn "" match output with | Ok o -> o |> Array.iter (printf "%02x") printfn "" Seq.fold2 (fun res b1 b2 -> res && b1 = b2) true input o | Error e -> false
This shows us what the function writing a log would look like (the writeLogMessage part), and what reading a log looks like (the readLogMessage part).
