Uploaded image for project: 'Apache NiFi'
  1. Apache NiFi
  2. NIFI-8114

Timer-driven ListFile processor sometimes doesn't start

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 1.11.4
    • Fix Version/s: None
    • Component/s: Extensions
    • Environment:
      Nifi on kunernates

      Description

      I have a nifi flow doing a list/fetch file. ListFile processor is scheduled using a CRON Driven strategy every day at 10:45 (0 45 10 * * ?). My problem is that sometimes this processor doesn't start even if the source directory contains file to list and files timestamp is greater than timestamp store in state (I use tracking timestamp strategy). If I stop the processor, change the scheduling time and start then it works.

      • Today I set log level to DEBUG for listFile class in logback.xml and at 10:45 obtain these log lines:

      2021-01-05 10:45:00,001 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Returning CLUSTER State: StandardStateMap[version=55, va
      lues={id.0=/opt/datafiles/ERMES/2021/01/04/CM_OWNER_1.CMT_DOMANDE_ACC_20210104-07_16_18.csv, processed.timestamp=1609740980291, listing.timestamp=1609740980291}]
      2021-01-05 10:45:00,001 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] has chosen to yield its resources; will not be scheduled
      to run again for 1000 milliseconds

      Files didn't listed.

      • Then I stop the processor, modify the scheduling time to 10:50 and then start it:

      2021-01-05 10:48:17,369 INFO [NiFi Web Server-1888443] o.a.n.c.s.StandardProcessScheduler Stopping ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf]
      2021-01-05 10:48:17,369 INFO [NiFi Web Server-1888443] o.a.n.controller.StandardProcessorNode Stopping processor: ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf]
      2021-01-05 10:48:17,369 INFO [Timer-Driven Process Thread-7] o.a.n.c.scheduling.QuartzSchedulingAgent Stopped scheduling ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] to run

      2021-01-05 10:48:30,370 INFO [Flow Service Tasks Thread-2] o.a.nifi.controller.StandardFlowService Saved flow controller org.apache.nifi.controller.FlowController@2ab3a38b // Another save pending = false
      2021-01-05 10:48:30,596 INFO [NiFi Web Server-1888901] o.a.n.c.s.StandardProcessScheduler Starting ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf]
      2021-01-05 10:48:30,596 INFO [NiFi Web Server-1888901] o.a.n.controller.StandardProcessorNode Starting ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf]
      2021-01-05 10:48:30,597 DEBUG [Timer-Driven Process Thread-5] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Returning CLUSTER State: StandardStateMap[version=55, va
      lues={id.0=/opt/datafiles/ERMES/2021/01/04/CM_OWNER_1.CMT_DOMANDE_ACC_20210104-07_16_18.csv, processed.timestamp=1609740980291, listing.timestamp=1609740980291}]
      2021-01-05 10:48:30,597 INFO [Timer-Driven Process Thread-5] o.a.n.c.scheduling.QuartzSchedulingAgent Scheduled ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] to run with 1 threads on schedule 0 50 10 *
      * ?

      • And at 10:50 it seems to work:

      2021-01-05 10:50:00,003 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Over the past 0 seconds, for Operation 'RETRIEVE_BASIC_A
      TTRIBUTES' there were no operations performed
      2021-01-05 10:50:00,003 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Over the past 0 seconds, for Operation 'RETRIEVE_OWNER_A
      TTRIBUTES' there were no operations performed
      2021-01-05 10:50:00,003 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Over the past 0 seconds, for Operation 'RETRIEVE_POSIX_A
      TTRIBUTES' there were no operations performed
      2021-01-05 10:50:00,004 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Over the past 0 seconds, for Operation 'CHECK_HIDDEN' th
      ere were no operations performed
      2021-01-05 10:50:00,004 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Over the past 0 seconds, for Operation 'CHECK_READABLE'
      there were no operations performed
      2021-01-05 10:50:00,004 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Over the past 0 seconds, for Operation 'FILTER' there we
      re no operations performed
      2021-01-05 10:50:00,004 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Over the past 0 seconds, for Operation 'RETRIEVE_NEXT_FI
      LE_FROM_OS' there were no operations performed
      2021-01-05 10:50:00,167 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Took 166 milliseconds to perform listing and gather 27 e
      ntries

      2021-01-05 10:50:00,177 INFO [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Successfully created listing with 27 new objects
      2021-01-05 10:50:00,180 DEBUG [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.ListFile ListFile[id=5b8735a7-484a-19e7-957e-9a51673c4eaf] Setting CLUSTER State to

      {id.0=/opt/datafiles/ERMES/2021 /01/05/CM_OWNER_1.CMT_DOMANDE_ACC_20210105-07_16_14.csv, processed.timestamp=1609827375913, listing.timestamp=1609827375913}

       

       

       

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              annalisa.asta Annalisa Asta
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated: