DevFW-CICD/ingress-nginx-helm
6
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Migrate to structured logging (klog)

Browse source
This commit is contained in:
Manuel Alejandro de Brito Fontes 2020-09-27 17:32:40 -03:00
parent 93ac8d5a21
commit 108637bb1c
31 changed files with 161 additions and 171 deletions
Download patch file Download diff file Expand all files Collapse all files

15
internal/ingress/controller/controller.go
View file

@ -135,14 +135,14 @@ func (n *NGINXController) syncIngress(interface{}) error {
n.metricCollector.SetSSLExpireTime(servers)
if n.runningConfig.Equal(pcfg) {
klog.V(3).Infof("No configuration change detected, skipping backend reload.")
klog.V(3).Infof("No configuration change detected, skipping backend reload")
return nil
}
n.metricCollector.SetHosts(hosts)
if !n.IsDynamicConfigurationEnough(pcfg) {
klog.Infof("Configuration changes detected, backend reload required.")
klog.InfoS("Configuration changes detected, backend reload required")
hash, _ := hashstructure.Hash(pcfg, &hashstructure.HashOptions{
TagName: "json",
@ -159,7 +159,7 @@ func (n *NGINXController) syncIngress(interface{}) error {
return err
}
klog.Infof("Backend successfully reloaded.")
klog.InfoS("Backend successfully reloaded")
n.metricCollector.ConfigSuccess(hash, true)
n.metricCollector.IncReloadCount()
@ -170,7 +170,7 @@ func (n *NGINXController) syncIngress(interface{}) error {
if isFirstSync {
// For the initial sync it always takes some time for NGINX to start listening
// For large configurations it might take a while so we loop and back off
klog.Info("Initial sync, sleeping for 1 second.")
klog.InfoS("Initial sync, sleeping for 1 second")
time.Sleep(1 * time.Second)
}
@ -1142,7 +1142,7 @@ func (n *NGINXController) createServers(data []*ingress.Ingress,
tlsSecretName := extractTLSSecretName(host, ing, n.store.GetLocalSSLCert)
if tlsSecretName == "" {
klog.V(3).Infof("Host %q is listed in the TLS section but secretName is empty. Using default certificate.", host)
klog.V(3).Infof("Host %q is listed in the TLS section but secretName is empty. Using default certificate", host)
servers[host].SSLCert = n.getDefaultSSLCertificate()
continue
}
@ -1165,13 +1165,12 @@ func (n *NGINXController) createServers(data []*ingress.Ingress,
err = cert.Certificate.VerifyHostname(host)
if err != nil {
klog.Warningf("Unexpected error validating SSL certificate %q for server %q: %v", secrKey, host, err)
klog.Warning("Validating certificate against DNS names. This will be deprecated in a future version.")
klog.Warning("Validating certificate against DNS names. This will be deprecated in a future version")
// check the Common Name field
// https://github.com/golang/go/issues/22922
err := verifyHostname(host, cert.Certificate)
if err != nil {
klog.Warningf("SSL certificate %q does not contain a Common Name or Subject Alternative Name for server %q: %v",
secrKey, host, err)
klog.Warningf("SSL certificate %q does not contain a Common Name or Subject Alternative Name for server %q: %v", secrKey, host, err)
klog.Warningf("Using default certificate")
servers[host].SSLCert = n.getDefaultSSLCertificate()
continue

51
internal/ingress/controller/nginx.go
View file

@ -147,16 +147,12 @@ func NewNGINXController(config *Configuration, mc metric.Collector) *NGINXContro
template, err := ngx_template.NewTemplate(nginx.TemplatePath)
if err != nil {
// this error is different from the rest because it must be clear why nginx is not working
klog.Errorf(`
-------------------------------------------------------------------------------
Error loading new template: %v
-------------------------------------------------------------------------------
`, err)
klog.ErrorS(err, "Error loading new template")
return
}
n.t = template
klog.Info("New NGINX configuration template loaded.")
klog.InfoS("New NGINX configuration template loaded")
n.syncQueue.EnqueueTask(task.GetDummyObject("template-change"))
}
@ -192,7 +188,7 @@ Error loading new template: %v
for _, f := range filesToWatch {
_, err = watch.NewFileWatcher(f, func() {
klog.Infof("File %v changed. Reloading NGINX", f)
klog.InfoS("File changed detected. Reloading NGINX", "path", f)
n.syncQueue.EnqueueTask(task.GetDummyObject("file-change"))
})
if err != nil {
@ -250,7 +246,7 @@ type NGINXController struct {
// Start starts a new NGINX master process running in the foreground.
func (n *NGINXController) Start() {
klog.Info("Starting NGINX Ingress controller")
klog.InfoS("Starting NGINX Ingress controller")
n.store.Run(n.stopCh)
@ -292,7 +288,7 @@ func (n *NGINXController) Start() {
n.setupSSLProxy()
}
klog.Info("Starting NGINX process")
klog.InfoS("Starting NGINX process")
n.start(cmd)
go n.syncQueue.Run(time.Second, n.stopCh)
@ -306,15 +302,16 @@ func (n *NGINXController) Start() {
time.Sleep(5 * time.Minute)
err := cleanTempNginxCfg()
if err != nil {
klog.Infof("Unexpected error removing temporal configuration files: %v", err)
klog.ErrorS(err, "Unexpected error removing temporal configuration files")
}
}
}()
if n.validationWebhookServer != nil {
klog.Infof("Starting validation webhook on %s with keys %s %s", n.validationWebhookServer.Addr, n.cfg.ValidationWebhookCertPath, n.cfg.ValidationWebhookKeyPath)
klog.InfoS("Starting validation webhook", "address", n.validationWebhookServer.Addr,
"certPath", n.cfg.ValidationWebhookCertPath, "keyPath", n.cfg.ValidationWebhookKeyPath)
go func() {
klog.Error(n.validationWebhookServer.ListenAndServeTLS("", ""))
klog.ErrorS(n.validationWebhookServer.ListenAndServeTLS("", ""), "Error listening for TLS connections")
}()
}
@ -337,7 +334,7 @@ func (n *NGINXController) Start() {
}
if evt, ok := event.(store.Event); ok {
klog.V(3).Infof("Event %v received - object %v", evt.Type, evt.Obj)
klog.V(3).InfoS("Event received", "type", evt.Type, "object", evt.Obj)
if evt.Type == store.ConfigurationEvent {
// TODO: is this necessary? Consider removing this special case
n.syncQueue.EnqueueTask(task.GetDummyObject("configmap-change"))
@ -365,7 +362,7 @@ func (n *NGINXController) Stop() error {
return fmt.Errorf("shutdown already in progress")
}
klog.Info("Shutting down controller queues")
klog.InfoS("Shutting down controller queues")
close(n.stopCh)
go n.syncQueue.Shutdown()
if n.syncStatus != nil {
@ -373,7 +370,7 @@ func (n *NGINXController) Stop() error {
}
if n.validationWebhookServer != nil {
klog.Info("Stopping admission controller")
klog.InfoS("Stopping admission controller")
err := n.validationWebhookServer.Close()
if err != nil {
return err
@ -381,7 +378,7 @@ func (n *NGINXController) Stop() error {
}
// send stop signal to NGINX
klog.Info("Stopping NGINX process")
klog.InfoS("Stopping NGINX process")
cmd := n.command.ExecCommand("-s", "quit")
cmd.Stdout = os.Stdout
cmd.Stderr = os.Stderr
@ -394,7 +391,7 @@ func (n *NGINXController) Stop() error {
timer := time.NewTicker(time.Second * 1)
for range timer.C {
if !nginx.IsRunning() {
klog.Info("NGINX process has stopped")
klog.InfoS("NGINX process has stopped")
timer.Stop()
break
}
@ -495,13 +492,13 @@ func (n NGINXController) generateTemplate(cfg ngx_config.Configuration, ingressC
nameHashBucketSize := nginxHashBucketSize(longestName)
if cfg.ServerNameHashBucketSize < nameHashBucketSize {
klog.V(3).Infof("Adjusting ServerNameHashBucketSize variable to %d", nameHashBucketSize)
klog.V(3).InfoS("Adjusting ServerNameHashBucketSize variable", "value", nameHashBucketSize)
cfg.ServerNameHashBucketSize = nameHashBucketSize
}
serverNameHashMaxSize := nextPowerOf2(serverNameBytes)
if cfg.ServerNameHashMaxSize < serverNameHashMaxSize {
klog.V(3).Infof("Adjusting ServerNameHashMaxSize variable to %d", serverNameHashMaxSize)
klog.V(3).InfoS("Adjusting ServerNameHashMaxSize variable", "value", serverNameHashMaxSize)
cfg.ServerNameHashMaxSize = serverNameHashMaxSize
}
@ -509,23 +506,23 @@ func (n NGINXController) generateTemplate(cfg ngx_config.Configuration, ingressC
// the limit of open files is per worker process
// and we leave some room to avoid consuming all the FDs available
wp, err := strconv.Atoi(cfg.WorkerProcesses)
klog.V(3).Infof("Number of worker processes: %d", wp)
klog.V(3).InfoS("Worker processes", "count", wp)
if err != nil {
wp = 1
}
maxOpenFiles := (rlimitMaxNumFiles() / wp) - 1024
klog.V(3).Infof("Maximum number of open file descriptors: %d", maxOpenFiles)
klog.V(3).InfoS("Maximum number of open file descriptors", "value", maxOpenFiles)
if maxOpenFiles < 1024 {
// this means the value of RLIMIT_NOFILE is too low.
maxOpenFiles = 1024
}
klog.V(3).Infof("Adjusting MaxWorkerOpenFiles variable to %d", maxOpenFiles)
klog.V(3).InfoS("Adjusting MaxWorkerOpenFiles variable", "value", maxOpenFiles)
cfg.MaxWorkerOpenFiles = maxOpenFiles
}
if cfg.MaxWorkerConnections == 0 {
maxWorkerConnections := int(float64(cfg.MaxWorkerOpenFiles * 3.0 / 4))
klog.V(3).Infof("Adjusting MaxWorkerConnections variable to %d", maxWorkerConnections)
klog.V(3).InfoS("Adjusting MaxWorkerConnections variable", "value", maxWorkerConnections)
cfg.MaxWorkerConnections = maxWorkerConnections
}
@ -684,7 +681,7 @@ func (n *NGINXController) OnUpdate(ingressCfg ingress.Configuration) error {
}
}
klog.Infof("NGINX configuration diff:\n%v", string(diffOutput))
klog.InfoS("NGINX configuration change", "diff", string(diffOutput))
// we do not defer the deletion of temp files in order
// to keep them around for inspection in case of error
@ -735,7 +732,7 @@ func (n *NGINXController) setupSSLProxy() {
sslPort := n.cfg.ListenPorts.HTTPS
proxyPort := n.cfg.ListenPorts.SSLProxy
klog.Info("Starting TLS proxy for SSL Passthrough")
klog.InfoS("Starting TLS proxy for SSL Passthrough")
n.Proxy = &TCPProxy{
Default: &TCPServer{
Hostname: "localhost",
@ -771,7 +768,7 @@ func (n *NGINXController) setupSSLProxy() {
continue
}
klog.V(3).Infof("Handling connection from remote address %s to local %s", conn.RemoteAddr(), conn.LocalAddr())
klog.V(3).InfoS("Handling TCP connection", "remote", conn.RemoteAddr(), "local", conn.LocalAddr())
go n.Proxy.Handle(conn)
}
}()
@ -1146,7 +1143,7 @@ func buildRedirects(servers []*ingress.Server) []*redirect {
continue
}
klog.V(3).Infof("Creating redirect from %q to %q", from, to)
klog.V(3).InfoS("Creating redirect", "from", from, "to", to)
found := false
for _, esrv := range servers {
if esrv.Hostname == from {

6
internal/ingress/controller/status.go
View file

@ -60,7 +60,7 @@ func setupLeaderElection(config *leaderElectionConfig) {
var stopCh chan struct{}
callbacks := leaderelection.LeaderCallbacks{
OnStartedLeading: func(ctx context.Context) {
klog.V(2).Infof("I am the new leader")
klog.V(2).InfoS("I am the new leader")
stopCh = make(chan struct{})
if config.OnStartedLeading != nil {
@ -68,7 +68,7 @@ func setupLeaderElection(config *leaderElectionConfig) {
}
},
OnStoppedLeading: func() {
klog.V(2).Info("I am not leader anymore")
klog.V(2).InfoS("I am not leader anymore")
close(stopCh)
// cancel the context
@ -81,7 +81,7 @@ func setupLeaderElection(config *leaderElectionConfig) {
}
},
OnNewLeader: func(identity string) {
klog.Infof("new leader elected: %v", identity)
klog.InfoS("New leader elected", "identity", identity)
},
}

10
internal/ingress/controller/store/backend_ssl.go
View file

@ -38,7 +38,7 @@ func (s *k8sStore) syncSecret(key string) {
s.syncSecretMu.Lock()
defer s.syncSecretMu.Unlock()
klog.V(3).Infof("Syncing Secret %q", key)
klog.V(3).InfoS("Syncing Secret", "name", key)
cert, err := s.getPemCertificate(key)
if err != nil {
@ -55,7 +55,7 @@ func (s *k8sStore) syncSecret(key string) {
// no need to update
return
}
klog.Infof("Updating Secret %q in the local store", key)
klog.InfoS("Updating secret in local store", "name", key)
s.sslStore.Update(key, cert)
// this update must trigger an update
// (like an update event from a change in Ingress)
@ -63,7 +63,7 @@ func (s *k8sStore) syncSecret(key string) {
return
}
klog.Infof("Adding Secret %q to the local store", key)
klog.InfoS("Adding secret to local store", "name", key)
s.sslStore.Add(key, cert)
// this update must trigger an update
// (like an update event from a change in Ingress)
@ -142,7 +142,7 @@ func (s *k8sStore) getPemCertificate(secretName string) (*ingress.SSLCert, error
msg += " and CRL"
}
klog.V(3).Info(msg)
klog.V(3).InfoS(msg)
} else if len(ca) > 0 {
sslCert, err = ssl.CreateCACert(ca)
if err != nil {
@ -162,7 +162,7 @@ func (s *k8sStore) getPemCertificate(secretName string) (*ingress.SSLCert, error
}
// makes this secret in 'syncSecret' to be used for Certificate Authentication
// this does not enable Certificate Authentication
klog.V(3).Infof("Configuring Secret %q for TLS authentication", secretName)
klog.V(3).InfoS("Configuring Secret for TLS authentication", "secret", secretName)
} else {
if auth != nil {
return nil, ErrSecretForAuth

34
internal/ingress/controller/store/store.go
View file

@ -287,7 +287,7 @@ func New(
// If we reached here it means the ingress was deleted but its final state is unrecorded.
tombstone, ok := obj.(cache.DeletedFinalStateUnknown)
if !ok {
klog.Errorf("couldn't get object from tombstone %#v", obj)
klog.ErrorS(nil, "Error obtaining object from tombstone", "key", obj)
return
}
ing, ok = tombstone.Obj.(*networkingv1beta1.Ingress)
@ -298,13 +298,14 @@ func New(
}
if !class.IsValid(ing) {
klog.Infof("ignoring delete for ingress %v based on annotation %v", ing.Name, class.IngressKey)
return
}
if isCatchAllIngress(ing.Spec) && disableCatchAll {
klog.Infof("ignoring delete for catch-all ingress %v/%v because of --disable-catch-all", ing.Namespace, ing.Name)
klog.InfoS("Ignoring delete for catch-all because of --disable-catch-all", "namespace", ing.Namespace, "ingress", ing.Name)
return
}
recorder.Eventf(ing, corev1.EventTypeNormal, "DELETE", fmt.Sprintf("Ingress %s/%s", ing.Namespace, ing.Name))
store.listers.IngressWithAnnotation.Delete(ing)
@ -323,11 +324,11 @@ func New(
ing, _ := toIngress(obj)
if !class.IsValid(ing) {
a, _ := parser.GetStringAnnotation(class.IngressKey, ing)
klog.Infof("ignoring add for ingress %v based on annotation %v with value %v", ing.Name, class.IngressKey, a)
klog.InfoS("Ignoring add for ingress based on annotation", "namespace", ing.Namespace, "ingress", ing.Name, "annotation", a)
return
}
if isCatchAllIngress(ing.Spec) && disableCatchAll {
klog.Infof("ignoring add for catch-all ingress %v/%v because of --disable-catch-all", ing.Namespace, ing.Name)
klog.InfoS("Ignoring add for catch-all ingress because of --disable-catch-all", "namespace", ing.Namespace, "ingress", ing.Name)
return
}
recorder.Eventf(ing, corev1.EventTypeNormal, "CREATE", fmt.Sprintf("Ingress %s/%s", ing.Namespace, ing.Name))
@ -350,26 +351,26 @@ func New(
validCur := class.IsValid(curIng)
if !validOld && validCur {
if isCatchAllIngress(curIng.Spec) && disableCatchAll {
klog.Infof("ignoring update for catch-all ingress %v/%v because of --disable-catch-all", curIng.Namespace, curIng.Name)
klog.InfoS("ignoring update for catch-all ingress because of --disable-catch-all", "namespace", curIng.Namespace, "ingress", curIng.Name)
return
}
klog.Infof("creating ingress %v based on annotation %v", curIng.Name, class.IngressKey)
klog.InfoS("creating ingress", "namespace", curIng.Namespace, "ingress", curIng.Name, "class", class.IngressKey)
recorder.Eventf(curIng, corev1.EventTypeNormal, "CREATE", fmt.Sprintf("Ingress %s/%s", curIng.Namespace, curIng.Name))
} else if validOld && !validCur {
klog.Infof("removing ingress %v based on annotation %v", curIng.Name, class.IngressKey)
klog.InfoS("removing ingress", "namespace", curIng.Namespace, "ingress", curIng.Name, "class", class.IngressKey)
ingDeleteHandler(old)
return
} else if validCur && !reflect.DeepEqual(old, cur) {
if isCatchAllIngress(curIng.Spec) && disableCatchAll {
klog.Infof("ignoring update for catch-all ingress %v/%v and delete old one because of --disable-catch-all", curIng.Namespace, curIng.Name)
klog.InfoS("ignoring update for catch-all ingress and delete old one because of --disable-catch-all", "namespace", curIng.Namespace, "ingress", curIng.Name)
ingDeleteHandler(old)
return
}
recorder.Eventf(curIng, corev1.EventTypeNormal, "UPDATE", fmt.Sprintf("Ingress %s/%s", curIng.Namespace, curIng.Name))
} else {
klog.V(3).Infof("No changes on ingress %v/%v. Skipping update", curIng.Namespace, curIng.Name)
klog.V(3).InfoS("No changes on ingress. Skipping update", "namespace", curIng.Namespace, "ingress", curIng.Name)
return
}
@ -395,7 +396,7 @@ func New(
// find references in ingresses and update local ssl certs
if ings := store.secretIngressMap.Reference(key); len(ings) > 0 {
klog.Infof("secret %v was added and it is used in ingress annotations. Parsing...", key)
klog.InfoS("Secret was added and it is used in ingress annotations. Parsing", "secret", key)
for _, ingKey := range ings {
ing, err := store.getIngress(ingKey)
if err != nil {
@ -422,11 +423,11 @@ func New(
// find references in ingresses and update local ssl certs
if ings := store.secretIngressMap.Reference(key); len(ings) > 0 {
klog.Infof("secret %v was updated and it is used in ingress annotations. Parsing...", key)
klog.InfoS("secret was updated and it is used in ingress annotations. Parsing", "secret", key)
for _, ingKey := range ings {
ing, err := store.getIngress(ingKey)
if err != nil {
klog.Errorf("could not find Ingress %v in local store", ingKey)
klog.ErrorS(err, "could not find Ingress in local store", "ingress", ingKey)
continue
}
store.syncIngress(ing)
@ -445,12 +446,11 @@ func New(
// If we reached here it means the secret was deleted but its final state is unrecorded.
tombstone, ok := obj.(cache.DeletedFinalStateUnknown)
if !ok {
klog.Errorf("couldn't get object from tombstone %#v", obj)
return
}
sec, ok = tombstone.Obj.(*corev1.Secret)
if !ok {
klog.Errorf("Tombstone contained object that is not a Secret: %#v", obj)
return
}
}
@ -461,7 +461,7 @@ func New(
// find references in ingresses
if ings := store.secretIngressMap.Reference(key); len(ings) > 0 {
klog.Infof("secret %v was deleted and it is used in ingress annotations. Parsing...", key)
klog.InfoS("secret was deleted and it is used in ingress annotations. Parsing", "secret", key)
for _, ingKey := range ings {
ing, err := store.getIngress(ingKey)
if err != nil {
@ -859,7 +859,7 @@ func (s *k8sStore) setConfig(cmap *corev1.ConfigMap) {
s.backendConfig = ngx_template.ReadConfig(cmap.Data)
if s.backendConfig.UseGeoIP2 && !nginx.GeoLite2DBExists() {
klog.Warning("The GeoIP2 feature is enabled but the databases are missing. Disabling.")
klog.Warning("The GeoIP2 feature is enabled but the databases are missing. Disabling")
s.backendConfig.UseGeoIP2 = false
}

10
internal/ingress/controller/tcp.go
View file

@ -63,19 +63,19 @@ func (p *TCPProxy) Handle(conn net.Conn) {
length, err := conn.Read(data)
if err != nil {
klog.V(4).Infof("Error reading the first 4k of the connection: %v", err)
klog.V(4).ErrorS(err, "Error reading the first 4k of the connection")
return
}
proxy := p.Default
hostname, err := parser.GetHostname(data[:])
if err == nil {
klog.V(4).Infof("Parsed hostname from TLS Client Hello: %s", hostname)
klog.V(4).InfoS("TLS Client Hello", "host", hostname)
proxy = p.Get(hostname)
}
if proxy == nil {
klog.V(4).Info("There is no configured proxy for SSL connections.")
klog.V(4).InfoS("There is no configured proxy for SSL connections.")
return
}
@ -97,11 +97,11 @@ func (p *TCPProxy) Handle(conn net.Conn) {
protocol = "TCP6"
}
proxyProtocolHeader := fmt.Sprintf("PROXY %s %s %s %d %d\r\n", protocol, remoteAddr.IP.String(), localAddr.IP.String(), remoteAddr.Port, localAddr.Port)
klog.V(4).Infof("Writing Proxy Protocol header: %s", proxyProtocolHeader)
klog.V(4).InfoS("Writing Proxy Protocol", "header", proxyProtocolHeader)
_, err = fmt.Fprintf(clientConn, proxyProtocolHeader)
}
if err != nil {
klog.Errorf("Error writing Proxy Protocol header: %v", err)
klog.ErrorS(err, "Error writing Proxy Protocol header")
clientConn.Close()
} else {
_, err = clientConn.Write(data[:length])

2
internal/ingress/controller/template/template.go
View file

@ -100,7 +100,7 @@ func (t *Template) Write(conf config.TemplateConfig) ([]byte, error) {
if err != nil {
klog.Errorf("unexpected error: %v", err)
}
klog.Infof("NGINX configuration: %v", string(b))
klog.InfoS("NGINX", "configuration", string(b))
}
err := t.tmpl.Execute(tmplBuf, conf)

5
internal/ingress/controller/util.go
View file

@ -54,7 +54,7 @@ func upstreamName(namespace string, service string, port intstr.IntOrString) str
func sysctlSomaxconn() int {
maxConns, err := sysctl.New().GetSysctl("net/core/somaxconn")
if err != nil || maxConns < 512 {
klog.V(3).Infof("net.core.somaxconn=%v (using system default)", maxConns)
klog.V(3).InfoS("Using default net.core.somaxconn", "value", maxConns)
return 511
}
@ -66,10 +66,9 @@ func rlimitMaxNumFiles() int {
var rLimit syscall.Rlimit
err := syscall.Getrlimit(syscall.RLIMIT_NOFILE, &rLimit)
if err != nil {
klog.Errorf("Error reading system maximum number of open file descriptors (RLIMIT_NOFILE): %v", err)
klog.ErrorS(err, "Error reading system maximum number of open file descriptors (RLIMIT_NOFILE)")
return 0
}
klog.V(2).Infof("rlimit.max=%v", rLimit.Max)
return int(rLimit.Max)
}