Uploaded image for project: 'Nuxeo Platform'
  1. Nuxeo Platform
  2. NXP-30146

Fix random ftest error log on AuditStorageLogWriterPool

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 11.5
    • Fix Version/s: 11.x
    • Component/s: Audit, Streams
    • Tags:
    • Team:
      PLATFORM
    • Sprint:
      nxplatform #28
    • Story Points:
      1

      Description

      Following up on NXP-30110, an error log can be seen randomly when running functional tests (seen on https://jenkins.platform.dev.nuxeo.com/job/nuxeo/job/nuxeo/view/change-requests/job/PR-4633/7/)

      [2021-02-08T22:10:41.421Z] [Text Finder] Searching for pattern '.*ERROR.*' in file set 'ftests/**/log/server.log'...
      [2021-02-08T22:10:41.547Z] /home/jenkins/workspace/nuxeo_nuxeo_PR-4633/ftests/nuxeo-audit-storage-directory-ftests/target/tomcat/log/server.log:
      [2021-02-08T22:10:41.548Z] 2021-02-08T21:43:37,767 ERROR [AuditStorageLogWriterPool-00,in:20,inCheckpoint:0,out:0,lastRead:1612820617663,lastTimer:1612820617493,wm:211395623908278272,loop:29,record] [org.nuxeo.lib.stream.computation.AbstractComputation] Computation: AuditStorageLogWriter fails last record: audit-audit-00:+80169859547155, after retries.
      [2021-02-08T22:10:41.552Z] 2021-02-08T21:43:37,814 ERROR [AuditStorageLogWriterPool-00,in:20,inCheckpoint:0,out:0,lastRead:1612820617663,lastTimer:1612820617493,wm:211395623908278272,loop:29,record] [org.nuxeo.lib.stream.computation.log.ComputationRunner] Terminate computation: AuditStorageLogWriter due to previous failure
      [2021-02-08T22:10:42.560Z] [Text Finder] Finished searching for pattern '.*ERROR.*' in file set 'ftests/**/log/server.log'.
      [2021-02-08T22:10:42.560Z] [Text Finder] Setting build result to 'FAILURE'.
      

      Attached full server logs: server.log

      2021-02-08T21:43:36,667 WARN  [stream/metricsPool-00] [org.nuxeo.runtime.stream.StreamMetricsComputation] Instance elected to report stream metrics
      2021-02-08T21:43:36,705 WARN  [stream/introspectionPool-00] [org.nuxeo.ecm.core.bulk.introspection.StreamIntrospectionComputation] Instance elected to introspect Nuxeo Stream activity
      2021-02-08T21:43:37,767 ERROR [AuditStorageLogWriterPool-00,in:20,inCheckpoint:0,out:0,lastRead:1612820617663,lastTimer:1612820617493,wm:211395623908278272,loop:29,record] [org.nuxeo.lib.stream.computation.AbstractComputation] Computation: AuditStorageLogWriter fails last record: audit-audit-00:+80169859547155, after retries.
      java.lang.NullPointerException: null
      	at org.nuxeo.ecm.platform.audit.service.NXAuditEventsService.getAuditStorage(NXAuditEventsService.java:214) ~[nuxeo-platform-audit-core-PR-4633-11.5-SNAPSHOT.jar:?]
      	at org.nuxeo.audit.storage.stream.StreamAuditStorageWriter$AuditStorageLogWriterComputation.writeJsonEntriesToAudit(StreamAuditStorageWriter.java:122) ~[nuxeo-audit-storage-directory-PR-4633-11.5-SNAPSHOT.jar:?]
      	at org.nuxeo.audit.storage.stream.StreamAuditStorageWriter$AuditStorageLogWriterComputation.processTimer(StreamAuditStorageWriter.java:91) ~[nuxeo-audit-storage-directory-PR-4633-11.5-SNAPSHOT.jar:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.lambda$processTimerWithRetry$6(ComputationRunner.java:371) ~[nuxeo-stream-PR-4633-11.5-SNAPSHOT.jar:?]
      	at net.jodah.failsafe.Functions$10.call(Functions.java:252) ~[failsafe-1.1.1.jar:1.1.1]
      	at net.jodah.failsafe.SyncFailsafe.call(SyncFailsafe.java:145) ~[failsafe-1.1.1.jar:1.1.1]
      	at net.jodah.failsafe.SyncFailsafe.run(SyncFailsafe.java:81) ~[failsafe-1.1.1.jar:1.1.1]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processTimerWithRetry(ComputationRunner.java:371) ~[nuxeo-stream-PR-4633-11.5-SNAPSHOT.jar:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.lambda$processTimerWithTracing$2(ComputationRunner.java:346) ~[nuxeo-stream-PR-4633-11.5-SNAPSHOT.jar:?]
      	at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684) [?:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processTimerWithTracing(ComputationRunner.java:344) [nuxeo-stream-PR-4633-11.5-SNAPSHOT.jar:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processTimer(ComputationRunner.java:323) [nuxeo-stream-PR-4633-11.5-SNAPSHOT.jar:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processLoop(ComputationRunner.java:271) [nuxeo-stream-PR-4633-11.5-SNAPSHOT.jar:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:206) [nuxeo-stream-PR-4633-11.5-SNAPSHOT.jar:?]
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
      	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
      	at java.lang.Thread.run(Thread.java:834) [?:?]
      2021-02-08T21:43:37,814 ERROR [AuditStorageLogWriterPool-00,in:20,inCheckpoint:0,out:0,lastRead:1612820617663,lastTimer:1612820617493,wm:211395623908278272,loop:29,record] [org.nuxeo.lib.stream.computation.log.ComputationRunner] Terminate computation: AuditStorageLogWriter due to previous failure
      2021-02-08T21:43:37,952 INFO  [main] [org.nuxeo.runtime.osgi.OSGiRuntimeService] Nuxeo Platform Started
      ======================================================================
      = Component Loading Status: Pending: 0 / Missing: 0 / Unstarted: 0 / Total: 541
      ======================================================================
      

      This mechanism should not run before full server start

        Attachments

        1. server.log
          5 kB
          Anahide Tchertchian

          Issue Links

            Activity

              People

              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 1 hour
                  1h