github.com/elfadel/cilium@v1.6.12/pkg/proxy/logger/logger.go (about) 1 // Copyright 2016-2018 Authors of Cilium 2 // 3 // Licensed under the Apache License, Version 2.0 (the "License"); 4 // you may not use this file except in compliance with the License. 5 // You may obtain a copy of the License at 6 // 7 // http://www.apache.org/licenses/LICENSE-2.0 8 // 9 // Unless required by applicable law or agreed to in writing, software 10 // distributed under the License is distributed on an "AS IS" BASIS, 11 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 12 // See the License for the specific language governing permissions and 13 // limitations under the License. 14 15 package logger 16 17 import ( 18 "encoding/json" 19 "net" 20 "strconv" 21 "time" 22 23 "github.com/cilium/cilium/pkg/flowdebug" 24 "github.com/cilium/cilium/pkg/identity" 25 "github.com/cilium/cilium/pkg/lock" 26 "github.com/cilium/cilium/pkg/logging" 27 "github.com/cilium/cilium/pkg/logging/logfields" 28 "github.com/cilium/cilium/pkg/node" 29 "github.com/cilium/cilium/pkg/proxy/accesslog" 30 31 "github.com/sirupsen/logrus" 32 "gopkg.in/natefinch/lumberjack.v2" 33 ) 34 35 var ( 36 log = logging.DefaultLogger.WithField(logfields.LogSubsys, "proxy-logger") 37 38 logMutex lock.Mutex 39 logger *lumberjack.Logger 40 notifier LogRecordNotifier 41 logPath string 42 metadata []string 43 ) 44 45 // fields used for structured logging 46 const ( 47 FieldType = "type" 48 FieldVerdict = "verdict" 49 FieldCode = "code" 50 FieldMethod = "method" 51 FieldURL = "url" 52 FieldProtocol = "protocol" 53 FieldHeader = "header" 54 FieldFilePath = logfields.Path 55 FieldMessage = "message" 56 ) 57 58 // fields used for structured logging of Kafka messages 59 const ( 60 FieldKafkaAPIKey = "kafkaApiKey" 61 FieldKafkaAPIVersion = "kafkaApiVersion" 62 FieldKafkaCorrelationID = "kafkaCorrelationID" 63 ) 64 65 // LogRecord is a proxy log record based off accesslog.LogRecord. 66 type LogRecord struct { 67 accesslog.LogRecord 68 69 // endpointInfoRegistry provides access to any endpoint's information given 70 // its IP address. 71 endpointInfoRegistry EndpointInfoRegistry 72 73 // localEndpointInfo is the information on the local endpoint which 74 // either sent the request (for egress) or is receiving the request 75 // (for ingress) 76 localEndpointInfo *accesslog.EndpointInfo 77 } 78 79 // NewLogRecord creates a new log record and applies optional tags 80 // 81 // Example: 82 // record := logger.NewLogRecord(localEndpointInfoSource, flowType, 83 // observationPoint, logger.LogTags.Timestamp(time.Now())) 84 func NewLogRecord(endpointInfoRegistry EndpointInfoRegistry, localEndpointInfoSource EndpointInfoSource, t accesslog.FlowType, ingress bool, tags ...LogTag) *LogRecord { 85 var observationPoint accesslog.ObservationPoint 86 if ingress { 87 observationPoint = accesslog.Ingress 88 } else { 89 observationPoint = accesslog.Egress 90 } 91 92 lr := LogRecord{ 93 LogRecord: accesslog.LogRecord{ 94 Type: t, 95 ObservationPoint: observationPoint, 96 IPVersion: accesslog.VersionIPv4, 97 TransportProtocol: 6, 98 Timestamp: time.Now().UTC().Format(time.RFC3339Nano), 99 NodeAddressInfo: accesslog.NodeAddressInfo{}, 100 }, 101 endpointInfoRegistry: endpointInfoRegistry, 102 localEndpointInfo: getEndpointInfo(localEndpointInfoSource), 103 } 104 105 if ip := node.GetExternalIPv4(); ip != nil { 106 lr.LogRecord.NodeAddressInfo.IPv4 = ip.String() 107 } 108 109 if ip := node.GetIPv6(); ip != nil { 110 lr.LogRecord.NodeAddressInfo.IPv6 = ip.String() 111 } 112 113 for _, tagFn := range tags { 114 tagFn(&lr) 115 } 116 117 return &lr 118 } 119 120 // fillEndpointInfo tries to resolve the IP address and fills the EndpointInfo 121 // fields with either ReservedIdentityHost or ReservedIdentityWorld 122 func (lr *LogRecord) fillEndpointInfo(info *accesslog.EndpointInfo, ip net.IP) { 123 if ip.To4() != nil { 124 info.IPv4 = ip.String() 125 126 // first we try to resolve and check if the IP is 127 // same as Host 128 if node.IsHostIPv4(ip) { 129 lr.endpointInfoRegistry.FillEndpointIdentityByID(identity.ReservedIdentityHost, info) 130 } else if !lr.endpointInfoRegistry.FillEndpointIdentityByIP(ip, info) { 131 // If we are unable to resolve the HostIP as well 132 // as the cluster IP we mark this as a 'world' identity. 133 lr.endpointInfoRegistry.FillEndpointIdentityByID(identity.ReservedIdentityWorld, info) 134 } 135 } else { 136 info.IPv6 = ip.String() 137 138 if node.IsHostIPv6(ip) { 139 lr.endpointInfoRegistry.FillEndpointIdentityByID(identity.ReservedIdentityHost, info) 140 } else if !lr.endpointInfoRegistry.FillEndpointIdentityByIP(ip, info) { 141 lr.endpointInfoRegistry.FillEndpointIdentityByID(identity.ReservedIdentityWorld, info) 142 } 143 } 144 } 145 146 // fillIngressSourceInfo fills the EndpointInfo fields using identity sent by 147 // source. This is needed in ingress proxy while logging the source endpoint 148 // info. Since there will be 2 proxies on the same host, if both egress and 149 // ingress policies are set, the ingress policy cannot determine the source 150 // endpoint info based on ip address, as the ip address would be that of the 151 // egress proxy i.e host. 152 func (lr *LogRecord) fillIngressSourceInfo(info *accesslog.EndpointInfo, ip *net.IP, srcIdentity uint32) { 153 if srcIdentity != 0 { 154 if ip != nil { 155 if ip.To4() != nil { 156 info.IPv4 = ip.String() 157 } else { 158 info.IPv6 = ip.String() 159 } 160 } 161 lr.endpointInfoRegistry.FillEndpointIdentityByID(identity.NumericIdentity(srcIdentity), info) 162 } else { 163 // source security identity 0 is possible when somebody else other than 164 // the BPF datapath attempts to 165 // connect to the proxy. 166 // We should try to resolve if the identity belongs to reserved_host 167 // or reserved_world. 168 if ip != nil { 169 lr.fillEndpointInfo(info, *ip) 170 } else { 171 log.Warn("Missing security identity in source endpoint info") 172 } 173 } 174 } 175 176 // fillEgressDestinationInfo returns the destination EndpointInfo for a flow 177 // leaving the proxy at egress. 178 func (lr *LogRecord) fillEgressDestinationInfo(info *accesslog.EndpointInfo, ipstr string) { 179 ip := net.ParseIP(ipstr) 180 if ip != nil { 181 lr.fillEndpointInfo(info, ip) 182 } 183 } 184 185 // LogTag attaches a tag to a log record 186 type LogTag func(lr *LogRecord) 187 188 // LogTags are optional structured tags that can be attached to log records. 189 // See NewLogRecord() and ApplyTags() for example usage. 190 var LogTags logTags 191 192 type logTags struct{} 193 194 // Verdict attachs verdict information to the log record 195 func (logTags) Verdict(v accesslog.FlowVerdict, info string) LogTag { 196 return func(lr *LogRecord) { 197 lr.Verdict = v 198 lr.Info = info 199 } 200 } 201 202 // Timestamp overwrites the starting timestamp of the log record 203 func (logTags) Timestamp(ts time.Time) LogTag { 204 return func(lr *LogRecord) { 205 lr.Timestamp = ts.UTC().Format(time.RFC3339Nano) 206 } 207 } 208 209 // AddressingInfo is the information passed in via the Addressing() tag 210 type AddressingInfo struct { 211 SrcIPPort string 212 DstIPPort string 213 SrcIdentity uint32 214 } 215 216 // Addressing attaches addressing information about the source and destination 217 // to the logrecord 218 func (logTags) Addressing(i AddressingInfo) LogTag { 219 return func(lr *LogRecord) { 220 switch lr.ObservationPoint { 221 case accesslog.Ingress: 222 lr.DestinationEndpoint = *lr.localEndpointInfo 223 case accesslog.Egress: 224 lr.SourceEndpoint = *lr.localEndpointInfo 225 } 226 227 ipstr, port, err := net.SplitHostPort(i.SrcIPPort) 228 if err == nil { 229 ip := net.ParseIP(ipstr) 230 if ip != nil && ip.To4() == nil { 231 lr.IPVersion = accesslog.VersionIPV6 232 } 233 234 p, err := strconv.ParseUint(port, 10, 16) 235 if err == nil { 236 lr.SourceEndpoint.Port = uint16(p) 237 if lr.ObservationPoint == accesslog.Ingress { 238 lr.fillIngressSourceInfo(&lr.SourceEndpoint, &ip, i.SrcIdentity) 239 } 240 } 241 } 242 243 ipstr, port, err = net.SplitHostPort(i.DstIPPort) 244 if err == nil { 245 p, err := strconv.ParseUint(port, 10, 16) 246 if err == nil { 247 lr.DestinationEndpoint.Port = uint16(p) 248 if lr.ObservationPoint == accesslog.Egress { 249 lr.fillEgressDestinationInfo(&lr.DestinationEndpoint, ipstr) 250 } 251 } 252 } 253 } 254 } 255 256 // HTTP attaches HTTP information to the log record 257 func (logTags) HTTP(h *accesslog.LogRecordHTTP) LogTag { 258 return func(lr *LogRecord) { 259 lr.HTTP = h 260 } 261 } 262 263 // Kafka attaches Kafka information to the log record 264 func (logTags) Kafka(k *accesslog.LogRecordKafka) LogTag { 265 return func(lr *LogRecord) { 266 lr.Kafka = k 267 } 268 } 269 270 // DNS attaches DNS information to the log record 271 func (logTags) DNS(d *accesslog.LogRecordDNS) LogTag { 272 return func(lr *LogRecord) { 273 lr.DNS = d 274 } 275 } 276 277 // L7 attaches generic L7 information to the log record 278 func (logTags) L7(h *accesslog.LogRecordL7) LogTag { 279 return func(lr *LogRecord) { 280 lr.L7 = h 281 } 282 } 283 284 // ApplyTags applies tags to an existing log record 285 // 286 // Example: 287 // lr.ApplyTags(logger.LogTags.Verdict(verdict, info)) 288 func (lr *LogRecord) ApplyTags(tags ...LogTag) { 289 for _, tagFn := range tags { 290 tagFn(lr) 291 } 292 } 293 294 func (lr *LogRecord) getLogFields() *logrus.Entry { 295 fields := log.WithFields(logrus.Fields{ 296 FieldType: lr.Type, 297 FieldVerdict: lr.Verdict, 298 FieldMessage: lr.Info, 299 }) 300 301 if lr.HTTP != nil { 302 fields = fields.WithFields(logrus.Fields{ 303 FieldCode: lr.HTTP.Code, 304 FieldMethod: lr.HTTP.Method, 305 FieldURL: lr.HTTP.URL, 306 FieldProtocol: lr.HTTP.Protocol, 307 FieldHeader: lr.HTTP.Headers, 308 }) 309 } 310 311 if lr.Kafka != nil { 312 fields = fields.WithFields(logrus.Fields{ 313 FieldCode: lr.Kafka.ErrorCode, 314 FieldKafkaAPIKey: lr.Kafka.APIKey, 315 FieldKafkaAPIVersion: lr.Kafka.APIVersion, 316 FieldKafkaCorrelationID: lr.Kafka.CorrelationID, 317 }) 318 } 319 320 return fields 321 } 322 323 func (lr *LogRecord) getRawLogMessage() []byte { 324 b, err := json.Marshal(*lr) 325 if err != nil { 326 return []byte(err.Error()) 327 } 328 329 return append(b, byte('\n')) 330 } 331 332 // Log logs a record to the logfile and flushes the buffer 333 func (lr *LogRecord) Log() { 334 flowdebug.Log(lr.getLogFields(), "Logging flow record") 335 336 // Lock while writing access log so we serialize writes as we may have 337 // to reopen the logfile and parallel writes could fail because of that 338 logMutex.Lock() 339 defer logMutex.Unlock() 340 341 lr.Metadata = metadata 342 343 if notifier != nil { 344 notifier.NewProxyLogRecord(lr) 345 } 346 347 if logger == nil { 348 flowdebug.Log(log.WithField(FieldFilePath, logPath), 349 "Skipping writing to access log (logger nil)") 350 return 351 } 352 353 if _, err := logger.Write(lr.getRawLogMessage()); err != nil { 354 log.WithError(err).WithField(FieldFilePath, logPath). 355 Errorf("Error writing to access file") 356 } 357 } 358 359 // Called with lock held 360 func openLogfileLocked(lf string) error { 361 logPath = lf 362 log.WithField(FieldFilePath, logPath).Info("Opened access log") 363 364 logger = &lumberjack.Logger{ 365 Filename: lf, 366 MaxSize: 100, // megabytes 367 MaxBackups: 3, 368 MaxAge: 28, //days 369 Compress: true, // disabled by default 370 } 371 372 return nil 373 } 374 375 // LogRecordNotifier is the interface to implement LogRecord notifications 376 type LogRecordNotifier interface { 377 // NewProxyLogRecord is called for each new log record 378 NewProxyLogRecord(l *LogRecord) error 379 } 380 381 // OpenLogfile opens a file for logging 382 func OpenLogfile(lf string) error { 383 logMutex.Lock() 384 defer logMutex.Unlock() 385 386 return openLogfileLocked(lf) 387 } 388 389 // SetNotifier sets the notifier to call for all L7 records 390 func SetNotifier(n LogRecordNotifier) { 391 logMutex.Lock() 392 notifier = n 393 logMutex.Unlock() 394 } 395 396 // SetMetadata sets the metadata to include in each record 397 func SetMetadata(md []string) { 398 logMutex.Lock() 399 defer logMutex.Unlock() 400 401 metadata = md 402 }