Istio Mixer container logs causing high disk space usage

12/11/2018

I have an Istio-enabled EKS Cluster, and my nodes are constantly running out of disk space.

Calculating the overall disk usage lead me to the istio-mixer container, which has a log file using more than 50GB of disk space in only 12 days of uptime:

[root@ip-some-ip containers]# pwd
/var/lib/docker/containers

[root@ip-some-ip containers]# du -schx .[!.]* * | sort -h | tail -n 10
66M 8bf5e8ee5a03096c589ad8f53b9e1a3d3088ca67b0064f3796e406f00336b532
73M 657eca261461d10c5b1b81ab3078d2058b931a357395903808b0145b617c1662
101M    bb338296ff06ef42ae6177c8a88e63438c26c398a457dc3f5301ffcb4ef2682b
127M    21f2da86055ad76882730abf65d4465386bb85598f797f451e7ad66726243613
134M    9c2be24e8b9345659b6f208c9f2d4650bb1ece11e0c4b0793aa01fdfebadb44e
383M    5d5fdbe6813ddc3ff2f6eb96f62f8317bd73e24730e2f44ebc537367d9987142
419M    475f8dfc74c3df2bc95c47df56e37d1dfb9181fae9aa783dafabba8283023115
592M    9193c50e586e0c7ecaeb87cecd8be13714a5d6ccd6ea63557c034ef56b07772f
52G 9c6b3e4f26603471d0aa9b6a61b3da5a69001e6b9be34432ffa62d577738c149
54G total

[root@ip-192-168-228-194 containers]# du -hs 9c6b3e4*/*.log
52G 9c6b3e4f26603471d0aa9b6a61b3da5a69001e6b9be34432ffa62d577738c149-json.log

[root@ip-ip-some-ip containers]# docker ps -a | grep 9c6b3e4f2660
9c6b3e4f2660        d559bdcd7a88                                                       "/usr/local/bin/mi..."   12 days ago         Up 12 days                                     k8s_mixer_istio-telemetry-6b5579595f-fvm5x_istio-system_6324c262-f3b5-11e8-b615-0eccb0bb4724_0

My questions are:

  • This amount of log output is expected?
  • The mixer log level can be decreased? How? Changing it affects my telemetry metrics?
  • There is a way to configure a log "retention period"?

Additional info:

  • Istio v1.0.2 (deployed with the offical helm charts; no custom configs)
  • k8s v1.10.11-eks
  • The cluster has approximately 20 pods running in Istio-enabled namespaces
-- Eduardo Baitello
istio
kubernetes

2 Answers

12/13/2018

The default value of logging level in Mixer is info. And the logs provided by you, confirms that you have this settings. Therefore, a lot of redundant information gathered in logs and it is possible to decrease logging level for some sources.

You can change it in two ways:

  1. On working pod without restart.

    In your logs you can find the following line:

    2018-12-12T17:54:55.461261Z info    ControlZ available at 192.168.87.249:9876

    It means, that in the mixer container on 9876 port you can find Istio ControlZ web-interface. To get an access to it from a computer with installed kubectl, you need to run the following command:

    kubectl -n istio-system port-forward $(kubectl -n istio-system get pod -l istio=mixer,istio-mixer-type=telemetry -o jsonpath='{.items[0].metadata.name}') 9876:9876 &

    After that, in your browser go to the link http://localhost:9876/scopez/, and you will see the following dashboard, where you can change log levels:

    enter image description here

  2. Add --log_output_level flag to the istio-telemetry deployment for the mixer container.

    Here is the description for the flag from the mixer's documentation:

    --log_output_level string
    Comma-separated minimum per-scope logging level of messages to output, in the form of :,:,... where scope can be one of [adapters, api, attributes, default, grpcAdapter, loadshedding] and level can be one of [debug, info, warn, error, none] (default "default:info")

    Note, that for key --log_output_level attributes:warn,api:error in yaml file you need to use one of the following:

    • value - --log_output_level=attributes:warn,api:error or
    • values - --log_output_level and - attributes:warn,api:error on different lines

    The example of the deployment:

    apiVersion: extensions/v1beta1
    kind: Deployment
    metadata:
      annotations:
      labels:
        chart: mixer-1.0.4
        istio: mixer
        release: istio
      name: istio-telemetry
      namespace: istio-system
    spec:
      progressDeadlineSeconds: 600
      replicas: 2
      revisionHistoryLimit: 10
      selector:
        matchLabels:
          app: telemetry
          istio: mixer
          istio-mixer-type: telemetry
      strategy:
        rollingUpdate:
          maxSurge: 1
          maxUnavailable: 1
        type: RollingUpdate
      template:
        metadata:
          annotations:
            scheduler.alpha.kubernetes.io/critical-pod: ""
            sidecar.istio.io/inject: "false"
          creationTimestamp: null
          labels:
            app: telemetry
            istio: mixer
            istio-mixer-type: telemetry
        spec:
          containers:
          - args:                                                #Flags for the Mixer process
            - --address                                          #Flag on two different lines
            - unix:///sock/mixer.socket
            - --configStoreURL=k8s://                            #Flag with '='
            - --configDefaultNamespace=istio-system
            - --trace_zipkin_url=http://zipkin:9411/api/v1/spans
            - --log_output_level=attributes:warn,api:error       # <------ THIS LINE IS WHAT YOU ARE LOOKING FOR
            env:
            - name: GODEBUG
              value: gctrace=2
            image: docker.io/istio/mixer:1.0.4
            imagePullPolicy: IfNotPresent
            livenessProbe:
              failureThreshold: 3
              httpGet:
                path: /version
                port: 9093
                scheme: HTTP
              initialDelaySeconds: 5
              periodSeconds: 5
              successThreshold: 1
              timeoutSeconds: 1
            name: mixer
            ports:
            - containerPort: 9093
              protocol: TCP
            - containerPort: 42422
              protocol: TCP
            resources:
              requests:
                cpu: 10m
            terminationMessagePath: /dev/termination-log
            terminationMessagePolicy: File
            volumeMounts:
            - mountPath: /sock
              name: uds-socket
          - args:
            - proxy
            - --serviceCluster
            - istio-telemetry
            - --templateFile
            - /etc/istio/proxy/envoy_telemetry.yaml.tmpl
            - --controlPlaneAuthPolicy
            - MUTUAL_TLS
            env:
            - name: POD_NAME
              valueFrom:
                fieldRef:
                  apiVersion: v1
                  fieldPath: metadata.name
            - name: POD_NAMESPACE
              valueFrom:
                fieldRef:
                  apiVersion: v1
                  fieldPath: metadata.namespace
            - name: INSTANCE_IP
              valueFrom:
                fieldRef:
                  apiVersion: v1
                  fieldPath: status.podIP
            image: docker.io/istio/proxyv2:1.0.4
            imagePullPolicy: IfNotPresent
            name: istio-proxy
            ports:
            - containerPort: 15090
              name: http-envoy-prom
              protocol: TCP
            resources:
              requests:
                cpu: 10m
            terminationMessagePath: /dev/termination-log
            terminationMessagePolicy: File
            volumeMounts:
            - mountPath: /etc/certs
              name: istio-certs
              readOnly: true
            - mountPath: /sock
              name: uds-socket
          dnsPolicy: ClusterFirst
          restartPolicy: Always
          schedulerName: default-scheduler
          securityContext: {}
          serviceAccount: istio-mixer-service-account
          serviceAccountName: istio-mixer-service-account
          terminationGracePeriodSeconds: 30
          volumes:
          - name: istio-certs
            secret:
              defaultMode: 420
              optional: true
              secretName: istio.istio-mixer-service-account
          - emptyDir: {}
            name: uds-socket
    

Additionally, you can configure log rotation for mixer process using the following flags:

--log_rotate string The path for the optional rotating log file

--log_rotate_max_age int The maximum age in days of a log file beyond which the file is rotated (0 indicates no limit) (default 30)

--log_rotate_max_backups int The maximum number of log file backups to keep before older files are deleted (0 indicates no limit) (default 1000)

--log_rotate_max_size int The maximum size in megabytes of a log file beyond which the file is rotated (default 104857600)

However, I have no possibility to generate a huge amount of such logs and test how it works.

Links:

Unfortunately, the official documentation is not good, but maybe it helps somehow.

And as a bonus, here is the list of all mixer server flags.

-- Artem Golenyaev
Source: StackOverflow

4/10/2019

This is how I solved the problem and some useful information for new Istio versions.

Istio v1.0.2:

The huge amount of logs was being generated by the Stdio adapter:

The stdio adapter enables Istio to output logs and metrics to the local machine. Logs and metrics can be directed to Mixer’s standard output stream, standard error stream, or to any locally reachable file.

In Istio v1.0.2 this adapter was enabled by default, streaming the logs to Mixer container stderr. To temporarily solve this, I deleted the following rules:

kubectl delete rule stdio --namespace=istio-system
kubectl delete rule stdio-tcp --namespace=istio-system

Deleting these rules does not affect the Prometheus metrics (which are handled by another adapter).

Istio v1.1.0+:

In this version, Istio introduced the mixer.adapters.stdio.enabled to helm installation options, disabling the stdio adapter by default, and including the following comment:

# stdio is a debug adapter in istio-telemetry, it is not recommended for production use.

The changes were made in the following PRs:

-- Eduardo Baitello
Source: StackOverflow