2018-06-27 16:11:32 +03:00
|
|
|
-- This is taken from wai-logger and customised for our use
|
|
|
|
|
|
|
|
module Hasura.Server.Logging
|
2019-01-02 14:24:17 +03:00
|
|
|
( StartupLog(..)
|
2019-03-12 08:46:27 +03:00
|
|
|
, PGLog(..)
|
2019-04-29 09:22:48 +03:00
|
|
|
, mkInconsMetadataLog
|
2019-07-11 08:37:06 +03:00
|
|
|
, mkHttpAccessLog
|
|
|
|
, mkHttpErrorLog
|
2018-08-03 11:43:35 +03:00
|
|
|
, WebHookLog(..)
|
2018-09-27 14:22:49 +03:00
|
|
|
, WebHookLogger
|
2018-12-13 10:26:15 +03:00
|
|
|
, HttpException
|
2018-07-20 10:22:46 +03:00
|
|
|
) where
|
|
|
|
|
2018-06-27 16:11:32 +03:00
|
|
|
import Data.Aeson
|
2019-07-11 08:37:06 +03:00
|
|
|
import Data.Aeson.Casing
|
|
|
|
import Data.Aeson.TH
|
|
|
|
import Data.Bits (shift, (.&.))
|
|
|
|
import Data.ByteString.Char8 (ByteString)
|
|
|
|
import Data.Int (Int64)
|
|
|
|
import Data.List (find)
|
2018-06-27 16:11:32 +03:00
|
|
|
import Data.Time.Clock
|
2019-07-11 08:37:06 +03:00
|
|
|
import Data.Word (Word32)
|
|
|
|
import Network.Socket (SockAddr (..))
|
|
|
|
import System.ByteOrder (ByteOrder (..), byteOrder)
|
|
|
|
import Text.Printf (printf)
|
2018-10-25 12:37:57 +03:00
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
import qualified Data.ByteString.Char8 as BS
|
|
|
|
import qualified Data.ByteString.Lazy as BL
|
|
|
|
import qualified Data.Text as T
|
|
|
|
import qualified Network.HTTP.Types as N
|
|
|
|
import qualified Network.Wai as Wai
|
2018-10-25 12:37:57 +03:00
|
|
|
|
2019-01-02 14:24:17 +03:00
|
|
|
import Hasura.HTTP
|
2019-07-11 08:37:06 +03:00
|
|
|
import Hasura.Logging (EngineLogType (..))
|
2018-06-27 16:11:32 +03:00
|
|
|
import Hasura.Prelude
|
2019-07-11 08:37:06 +03:00
|
|
|
import Hasura.RQL.Types
|
2018-07-17 16:23:23 +03:00
|
|
|
import Hasura.Server.Utils
|
2019-01-02 14:24:17 +03:00
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
import qualified Hasura.Logging as L
|
|
|
|
|
2019-01-02 14:24:17 +03:00
|
|
|
data StartupLog
|
|
|
|
= StartupLog
|
|
|
|
{ slLogLevel :: !L.LogLevel
|
|
|
|
, slKind :: !T.Text
|
|
|
|
, slInfo :: !Value
|
|
|
|
} deriving (Show, Eq)
|
|
|
|
|
|
|
|
instance ToJSON StartupLog where
|
|
|
|
toJSON (StartupLog _ k info) =
|
|
|
|
object [ "kind" .= k
|
|
|
|
, "info" .= info
|
|
|
|
]
|
|
|
|
|
|
|
|
instance L.ToEngineLog StartupLog where
|
|
|
|
toEngineLog startupLog =
|
2019-07-11 08:37:06 +03:00
|
|
|
(slLogLevel startupLog, ELTStartup, toJSON startupLog)
|
2018-09-27 14:22:49 +03:00
|
|
|
|
2019-03-12 08:46:27 +03:00
|
|
|
data PGLog
|
|
|
|
= PGLog
|
|
|
|
{ plLogLevel :: !L.LogLevel
|
|
|
|
, plMessage :: !T.Text
|
|
|
|
} deriving (Show, Eq)
|
|
|
|
|
|
|
|
instance ToJSON PGLog where
|
|
|
|
toJSON (PGLog _ msg) =
|
|
|
|
object ["message" .= msg]
|
|
|
|
|
|
|
|
instance L.ToEngineLog PGLog where
|
|
|
|
toEngineLog pgLog =
|
2019-07-11 08:37:06 +03:00
|
|
|
(plLogLevel pgLog, ELTPgClient, toJSON pgLog)
|
2019-03-12 08:46:27 +03:00
|
|
|
|
2019-04-29 09:22:48 +03:00
|
|
|
data MetadataLog
|
|
|
|
= MetadataLog
|
|
|
|
{ mlLogLevel :: !L.LogLevel
|
|
|
|
, mlMessage :: !T.Text
|
|
|
|
, mlInfo :: !Value
|
|
|
|
} deriving (Show, Eq)
|
|
|
|
|
|
|
|
instance ToJSON MetadataLog where
|
|
|
|
toJSON (MetadataLog _ msg infoVal) =
|
|
|
|
object [ "message" .= msg
|
|
|
|
, "info" .= infoVal
|
|
|
|
]
|
|
|
|
|
|
|
|
instance L.ToEngineLog MetadataLog where
|
|
|
|
toEngineLog ml =
|
2019-07-11 08:37:06 +03:00
|
|
|
(mlLogLevel ml, ELTMetadata, toJSON ml)
|
2019-04-29 09:22:48 +03:00
|
|
|
|
|
|
|
mkInconsMetadataLog :: [InconsistentMetadataObj] -> MetadataLog
|
|
|
|
mkInconsMetadataLog objs =
|
|
|
|
MetadataLog L.LevelWarn "Inconsistent Metadata!" $
|
|
|
|
object [ "objects" .= objs]
|
|
|
|
|
2018-08-03 11:43:35 +03:00
|
|
|
data WebHookLog
|
|
|
|
= WebHookLog
|
|
|
|
{ whlLogLevel :: !L.LogLevel
|
|
|
|
, whlStatusCode :: !(Maybe N.Status)
|
|
|
|
, whlUrl :: !T.Text
|
2018-12-03 14:19:08 +03:00
|
|
|
, whlMethod :: !N.StdMethod
|
2018-12-13 10:26:15 +03:00
|
|
|
, whlError :: !(Maybe HttpException)
|
2018-08-03 11:43:35 +03:00
|
|
|
, whlResponse :: !(Maybe T.Text)
|
|
|
|
} deriving (Show)
|
|
|
|
|
|
|
|
instance L.ToEngineLog WebHookLog where
|
|
|
|
toEngineLog webHookLog =
|
2019-07-11 08:37:06 +03:00
|
|
|
(whlLogLevel webHookLog, ELTWebhookLog, toJSON webHookLog)
|
2018-08-03 11:43:35 +03:00
|
|
|
|
|
|
|
instance ToJSON WebHookLog where
|
2018-12-13 10:26:15 +03:00
|
|
|
toJSON whl =
|
|
|
|
object [ "status_code" .= (N.statusCode <$> whlStatusCode whl)
|
|
|
|
, "url" .= whlUrl whl
|
|
|
|
, "method" .= show (whlMethod whl)
|
|
|
|
, "http_error" .= whlError whl
|
|
|
|
, "response" .= whlResponse whl
|
|
|
|
]
|
2018-08-03 11:43:35 +03:00
|
|
|
|
2018-09-27 14:22:49 +03:00
|
|
|
type WebHookLogger = WebHookLog -> IO ()
|
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
-- | Log information about the HTTP request
|
|
|
|
data HttpInfoLog
|
|
|
|
= HttpInfoLog
|
|
|
|
{ hlStatus :: !N.Status
|
|
|
|
, hlMethod :: !T.Text
|
|
|
|
, hlSource :: !T.Text
|
|
|
|
, hlPath :: !T.Text
|
|
|
|
, hlHttpVersion :: !N.HttpVersion
|
2018-06-27 16:11:32 +03:00
|
|
|
} deriving (Show, Eq)
|
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
instance ToJSON HttpInfoLog where
|
|
|
|
toJSON (HttpInfoLog st met src path hv) =
|
2018-06-27 16:11:32 +03:00
|
|
|
object [ "status" .= N.statusCode st
|
|
|
|
, "method" .= met
|
|
|
|
, "ip" .= src
|
|
|
|
, "url" .= path
|
|
|
|
, "http_version" .= show hv
|
|
|
|
]
|
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
-- | Information about a GraphQL/Hasura metadata operation over HTTP
|
|
|
|
data OperationLog
|
|
|
|
= OperationLog
|
|
|
|
{ olRequestId :: !RequestId
|
|
|
|
, olUserVars :: !(Maybe UserVars)
|
|
|
|
, olResponseSize :: !(Maybe Int64)
|
|
|
|
, olQueryExecutionTime :: !(Maybe Double)
|
|
|
|
, olQuery :: !(Maybe Value)
|
|
|
|
, olError :: !(Maybe Value)
|
2018-06-27 16:11:32 +03:00
|
|
|
} deriving (Show, Eq)
|
2019-07-11 08:37:06 +03:00
|
|
|
$(deriveToJSON (aesonDrop 2 snakeCase) ''OperationLog)
|
2018-06-27 16:11:32 +03:00
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
data HttpAccessLog
|
|
|
|
= HttpAccessLog
|
|
|
|
{ halHttpInfo :: !HttpInfoLog
|
|
|
|
, halOperation :: !OperationLog
|
|
|
|
} deriving (Show, Eq)
|
|
|
|
$(deriveToJSON (aesonDrop 3 snakeCase) ''HttpAccessLog)
|
2018-06-27 16:11:32 +03:00
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
data HttpLog
|
|
|
|
= HttpLog
|
|
|
|
{ _hlLogLevel :: !L.LogLevel
|
|
|
|
, _hlLogLing :: !HttpAccessLog
|
|
|
|
}
|
|
|
|
|
|
|
|
instance L.ToEngineLog HttpLog where
|
|
|
|
toEngineLog (HttpLog logLevel accessLog) =
|
|
|
|
(logLevel, ELTHttpLog, toJSON accessLog)
|
|
|
|
|
|
|
|
mkHttpAccessLog
|
|
|
|
:: Maybe UserInfo -- may not have been resolved
|
|
|
|
-> RequestId
|
|
|
|
-> Wai.Request
|
|
|
|
-> BL.ByteString
|
|
|
|
-> Maybe (UTCTime, UTCTime)
|
|
|
|
-> HttpLog
|
|
|
|
mkHttpAccessLog userInfoM reqId req res mTimeT =
|
|
|
|
let http = HttpInfoLog
|
|
|
|
{ hlStatus = status
|
|
|
|
, hlMethod = bsToTxt $ Wai.requestMethod req
|
|
|
|
, hlSource = bsToTxt $ getSourceFromFallback req
|
|
|
|
, hlPath = bsToTxt $ Wai.rawPathInfo req
|
|
|
|
, hlHttpVersion = Wai.httpVersion req
|
|
|
|
}
|
|
|
|
op = OperationLog
|
|
|
|
{ olRequestId = reqId
|
|
|
|
, olUserVars = userVars <$> userInfoM
|
|
|
|
, olResponseSize = respSize
|
|
|
|
, olQueryExecutionTime = respTime
|
|
|
|
, olQuery = Nothing
|
|
|
|
, olError = Nothing
|
|
|
|
}
|
|
|
|
in HttpLog L.LevelInfo $ HttpAccessLog http op
|
2018-06-27 16:11:32 +03:00
|
|
|
where
|
2019-07-11 08:37:06 +03:00
|
|
|
status = N.status200
|
|
|
|
respSize = Just $ BL.length res
|
|
|
|
respTime = computeTimeDiff mTimeT
|
|
|
|
|
|
|
|
mkHttpErrorLog
|
2018-10-25 12:37:57 +03:00
|
|
|
:: Maybe UserInfo -- may not have been resolved
|
2019-07-11 08:37:06 +03:00
|
|
|
-> RequestId
|
|
|
|
-> Wai.Request
|
|
|
|
-> QErr
|
|
|
|
-> Maybe Value
|
2018-06-27 16:11:32 +03:00
|
|
|
-> Maybe (UTCTime, UTCTime)
|
2019-07-11 08:37:06 +03:00
|
|
|
-> HttpLog
|
|
|
|
mkHttpErrorLog userInfoM reqId req err query mTimeT =
|
|
|
|
let http = HttpInfoLog
|
|
|
|
{ hlStatus = status
|
|
|
|
, hlMethod = bsToTxt $ Wai.requestMethod req
|
|
|
|
, hlSource = bsToTxt $ getSourceFromFallback req
|
|
|
|
, hlPath = bsToTxt $ Wai.rawPathInfo req
|
|
|
|
, hlHttpVersion = Wai.httpVersion req
|
|
|
|
}
|
|
|
|
op = OperationLog
|
|
|
|
{ olRequestId = reqId
|
|
|
|
, olUserVars = userVars <$> userInfoM
|
|
|
|
, olResponseSize = respSize
|
|
|
|
, olQueryExecutionTime = respTime
|
|
|
|
, olQuery = toJSON <$> query
|
|
|
|
, olError = Just $ toJSON err
|
|
|
|
}
|
|
|
|
in HttpLog L.LevelError $ HttpAccessLog http op
|
2018-06-27 16:11:32 +03:00
|
|
|
where
|
2019-07-11 08:37:06 +03:00
|
|
|
status = qeStatus err
|
|
|
|
respSize = Just $ BL.length $ encode err
|
|
|
|
respTime = computeTimeDiff mTimeT
|
|
|
|
|
|
|
|
computeTimeDiff :: Maybe (UTCTime, UTCTime) -> Maybe Double
|
|
|
|
computeTimeDiff = fmap (realToFrac . uncurry (flip diffUTCTime))
|
2018-06-27 16:11:32 +03:00
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
getSourceFromSocket :: Wai.Request -> ByteString
|
|
|
|
getSourceFromSocket = BS.pack . showSockAddr . Wai.remoteHost
|
2018-06-27 16:11:32 +03:00
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
getSourceFromFallback :: Wai.Request -> ByteString
|
2018-06-27 16:11:32 +03:00
|
|
|
getSourceFromFallback req = fromMaybe (getSourceFromSocket req) $ getSource req
|
|
|
|
|
2019-07-11 08:37:06 +03:00
|
|
|
getSource :: Wai.Request -> Maybe ByteString
|
2018-06-27 16:11:32 +03:00
|
|
|
getSource req = addr
|
|
|
|
where
|
|
|
|
maddr = find (\x -> fst x `elem` ["x-real-ip", "x-forwarded-for"]) hdrs
|
|
|
|
addr = fmap snd maddr
|
2019-07-11 08:37:06 +03:00
|
|
|
hdrs = Wai.requestHeaders req
|
2018-06-27 16:11:32 +03:00
|
|
|
|
|
|
|
-- | A type for IP address in numeric string representation.
|
|
|
|
type NumericAddress = String
|
|
|
|
|
|
|
|
showIPv4 :: Word32 -> Bool -> NumericAddress
|
|
|
|
showIPv4 w32 little
|
|
|
|
| little = show b1 ++ "." ++ show b2 ++ "." ++ show b3 ++ "." ++ show b4
|
|
|
|
| otherwise = show b4 ++ "." ++ show b3 ++ "." ++ show b2 ++ "." ++ show b1
|
|
|
|
where
|
|
|
|
t1 = w32
|
|
|
|
t2 = shift t1 (-8)
|
|
|
|
t3 = shift t2 (-8)
|
|
|
|
t4 = shift t3 (-8)
|
|
|
|
b1 = t1 .&. 0x000000ff
|
|
|
|
b2 = t2 .&. 0x000000ff
|
|
|
|
b3 = t3 .&. 0x000000ff
|
|
|
|
b4 = t4 .&. 0x000000ff
|
|
|
|
|
|
|
|
showIPv6 :: (Word32,Word32,Word32,Word32) -> String
|
|
|
|
showIPv6 (w1,w2,w3,w4) =
|
|
|
|
printf "%x:%x:%x:%x:%x:%x:%x:%x" s1 s2 s3 s4 s5 s6 s7 s8
|
|
|
|
where
|
|
|
|
(s1,s2) = split16 w1
|
|
|
|
(s3,s4) = split16 w2
|
|
|
|
(s5,s6) = split16 w3
|
|
|
|
(s7,s8) = split16 w4
|
|
|
|
split16 w = (h1,h2)
|
|
|
|
where
|
|
|
|
h1 = shift w (-16) .&. 0x0000ffff
|
|
|
|
h2 = w .&. 0x0000ffff
|
|
|
|
|
|
|
|
-- | Convert 'SockAddr' to 'NumericAddress'. If the address is
|
|
|
|
-- IPv4-embedded IPv6 address, the IPv4 is extracted.
|
|
|
|
showSockAddr :: SockAddr -> NumericAddress
|
|
|
|
-- HostAddr is network byte order.
|
|
|
|
showSockAddr (SockAddrInet _ addr4) = showIPv4 addr4 (byteOrder == LittleEndian)
|
|
|
|
-- HostAddr6 is host byte order.
|
|
|
|
showSockAddr (SockAddrInet6 _ _ (0,0,0x0000ffff,addr4) _) = showIPv4 addr4 False
|
|
|
|
showSockAddr (SockAddrInet6 _ _ (0,0,0,1) _) = "::1"
|
|
|
|
showSockAddr (SockAddrInet6 _ _ addr6 _) = showIPv6 addr6
|
|
|
|
showSockAddr _ = "unknownSocket"
|