Uploaded image for project: 'Docs for Red Hat Developers'
  1. Docs for Red Hat Developers
  2. RHDEVDOCS-3277

Entry out of order when forward logs to loki

XMLWordPrintable

      Some records was not forward to Loki. huge amounts of messages in flushed log

      failed to POST http://loki-server.loki-aosqe.svc:3100/loki/api/v1/push (400 Bad Request entry with timestamp 2021-08-18 05:41:10.373584 +0000 UTC ignored, reason: 'entry out of order' for stream:

      {fluentd_thread="flush_thread_0", log_type="audit"},

      level=warn ts=2021-08-18T09:25:17.228731133Z caller=grpc_logging.go:38 duration=64.564µs method=/logproto.Pusher/Push err="rpc error: code = Code(400) desc = entry with timestamp 2021-08-18 09:25:14.681496 +0000 UTC ignored, reason: 'entry out of order' for stream:
      {fluentd_thread=\"flush_thread_0\", log_type=\"infrastructure\"},\nentry with timestamp 2021-08-18 09:25:14.682497 +0000 UTC ignored, reason: 'entry out of order' for stream: {fluentd_thread="flush_thread_0", log_type="infrastructure"}


      Step to reproduce:
      1. Deploy loki single process

      oc new-project loki-aosqe
      oc project loki-aosqe
      oc create sa loki-sa
      oc adm policy add-scc-to-user privileged system:serviceaccount:loki-aosqe:loki-sa

      wget https://raw.githubusercontent.com/grafana/loki/v2.3.0/cmd/loki/loki-local-config.yaml -O local-config.yaml
      oc create cm loki-config --from-file=loki-config.yaml=loki-config.yaml
      
      

       echo "kind: Deployment
      apiVersion: apps/v1
      metadata:
        name:  loki-server
        labels:
          provider: aosqe
          component: "loki"
          appname: loki-server
      spec:
        replicas: 1
        revisionHistoryLimit: 10
        selector:
          matchLabels:
            provider: aosqe
            component: "loki"
        strategy:
          type: Recreate
        template:
          metadata:
            labels:
              provider: aosqe
              component: "loki"
              appname: loki-server
          spec:
            serviceAccount: loki-sa
            serviceAccountName: loki-sa
            containers:
            - name: "loki"
              image: docker.io/grafana/loki:2.3.0
              imagePullPolicy: IfNotPresent
              securityContext:
                privileged: true
                procMount: Default
              ports:
              - containerPort: 3100
                name: tcp
                protocol: TCP
              volumeMounts:
              - mountPath: /etc/loki
                name: lokiconfig
                readOnly: true
            volumes:
            - configMap:
                defaultMode: 420
                name: loki-config
              name: lokiconfig
      ">loki-deployment.yaml
      


      oc create -f loki-deployment.yaml
      oc expose deployment loki-server

      2. forward audit log to loki
      echo "apiVersion: logging.openshift.io/v1
      kind: ClusterLogForwarder
      metadata:
        name: instance
        namespace: openshift-logging
      spec:
        outputs:
        outputs:
        - name: loki-server
          type: loki
          url: http://loki-server.loki-aosqe.svc:3100
        pipelines:
          - name: to-loki
            inputRefs:
            - application
            outputRefs:
            - loki-server">loki-clf.yaml
      oc create -f loki-clf.yaml
      


      3. Check the fluentd loki pod logs.


      Actual result:
      1) Logs of warn messages in fluentd pod. Please refer to the attached logs

      2) Loki report ntry out of order' for stream:
      
      

      level=warn ts=2021-08-18T06:06:51.553183641Z caller=grpc_logging.go:38 method=/logproto.Pusher/Push duration=90.326µs err="rpc error: code = Code(400) desc = entry with timestamp 2021-08-18 05:58:55.061936 +0000 UTC ignored, reason: 'entry out of order' for stream: {fluentd_thread="flush_thread_0", log_type="audit"}

      ,\nentry with timestamp 2021-08-18 05:58:55.061936 +0000 UTC ignored, reason: 'entry out of order' for stream:

      {fluentd_thread=\"flush_thread_0\", log_type=\"audit\"},\nentry with timestamp 2021-08-18 06:01:18.290229 +0000 UTC ignored, reason: 'entry out of order' for stream: {fluentd_thread="flush_thread_0", log_type="audit"}

      ,\nentry with timestamp 2021-08-18 06:01:18.290229 +0000 UTC ignored, reason: 'entry out of order' for stream:

      {fluentd_thread=\"flush_thread_0\", log_type=\"audit\"},\nentry with timestamp 2021-08-18 06:01:26.772308 +0000 UTC ignored, reason: 'entry out of order' for stream: {fluentd_thread="flush_thread_0", log_type="audit"}

      ,\nentry with timestamp 2021-08-18 06:01:26.772308 +0000 UTC ignored, reason: 'entry out of order' for stream:

      {fluentd_thread=\"flush_thread_0\", log_type=\"audit\"},\nentry with timestamp 2021-08-18 06:06:41.045394 +0000 UTC ignored, reason: 'entry out of order' for stream: {fluentd_thread="flush_thread_0", log_type="audit"}

      ,\nentry with timestamp 2021-08-18 06:06:41.045394 +0000 UTC ignored, reason: 'entry out of order' for stream:

      {fluentd_thread=\"flush_thread_0\", log_type=\"audit\"},\nentry with timestamp 2021-08-18 06:06:41.069429 +0000 UTC ignored, reason: 'entry out of order' for stream: {fluentd_thread="flush_thread_0", log_type="audit"}

      ,\nentry with timestamp 2021-08-18 06:06:41.069429 +0000 UTC ignored, reason: 'entry out of order' for stream:

      {fluentd_thread=\"flush_thread_0\", log_type=\"audit\"}

      ,\ntotal ignored: 14 out of 38" msg="gRPC\n"

      
      

       

      Expected result:
      The audit logs can be sent to Loki

              rdlugyhe Rolfe Dlugy-Hegwer
              rdlugyhe Rolfe Dlugy-Hegwer
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Created:
                Updated:
                Resolved: