Too frequently ACTIVATED message about one job(one instance)


#1

hi, I enable the debug log exporter,and i found that too many logs like this:

I found that ACTIVATED of the same job coming at 2019-05-30T06:59:00.519Z and 2019-05-30T06:59:00.616Z, does it too frequently? it is a normal behavior or something wrong?
thanks~

06:59:00.520 [exporter] [10.0.0.78:26501-zb-actors-1] DEBUG io.zeebe.broker.exporter.debug-log - {
  "key" : 1407598,
  "position" : 1249835488320,
  "timestamp" : "2019-05-30T06:59:00.519Z",
  "raftTerm" : 89,
  "producerId" : 0,
  "sourceRecordPosition" : 1249835488112,
  "metadata" : {
    "valueType" : "JOB_BATCH",
    "intent" : "ACTIVATED",
    "recordType" : "EVENT",
    "partitionId" : 0,
    "rejectionType" : "NULL_VAL",
    "rejectionReason" : ""
  },
  "value" : {
    "type" : "pCIJob",
    "worker" : "demo-pci-service#pCIJob",
    "timeout" : "PT5M",
    "maxJobsToActivate" : 32,
    "jobKeys" : [ ],
    "jobs" : [ ],
    "truncated" : false
  }
}
06:59:00.615 [exporter] [10.0.0.78:26501-zb-actors-0] DEBUG io.zeebe.broker.exporter.debug-log - {
  "key" : -1,
  "position" : 1249835488544,
  "timestamp" : "2019-05-30T06:59:00.614Z",
  "raftTerm" : 89,
  "producerId" : -1,
  "sourceRecordPosition" : -1,
  "metadata" : {
    "valueType" : "JOB_BATCH",
    "intent" : "ACTIVATE",
    "recordType" : "COMMAND",
    "partitionId" : 0,
    "rejectionType" : "NULL_VAL",
    "rejectionReason" : ""
  },
  "value" : {
    "type" : "pCIJob",
    "worker" : "demo-pci-service#pCIJob",
    "timeout" : "PT5M",
    "maxJobsToActivate" : 32,
    "jobKeys" : [ ],
    "jobs" : [ ],
    "truncated" : false
  }
}
06:59:00.618 [exporter] [10.0.0.78:26501-zb-actors-0] DEBUG io.zeebe.broker.exporter.debug-log - {
  "key" : 1407599,
  "position" : 1249835488752,
  "timestamp" : "2019-05-30T06:59:00.616Z",
  "raftTerm" : 89,
  "producerId" : 0,
  "sourceRecordPosition" : 1249835488544,
  "metadata" : {
    "valueType" : "JOB_BATCH",
    "intent" : "ACTIVATED",
    "recordType" : "EVENT",
    "partitionId" : 0,
    "rejectionType" : "NULL_VAL",
    "rejectionReason" : ""
  },
  "value" : {
    "type" : "pCIJob",
    "worker" : "demo-pci-service#pCIJob",
    "timeout" : "PT5M",
    "maxJobsToActivate" : 32,
    "jobKeys" : [ ],
    "jobs" : [ ],
    "truncated" : false
  }
}

#2

Hi @aximo, good work!

This is the activateJobs call from your worker. It’s not about one job, it’s about the taskType of the job worker. Try stopping the worker and you should see these stop.

In 0.18-SNAPSHOT you can apply a filter directly in the exporter.

The DebugExporter doesn’t implement it, but you could use this blog post and the code for the DebugExporter to write one that does.


#3

You make a RecordFilter like this:

public class RecordFilter implements Context.RecordFilter {

    RecordFilter() {

    }

    @Override
    public boolean acceptType(RecordType recordType) {

    }

    @Override
    public boolean acceptValue(ValueType valueType) {
        return !valueType.equals(ValueType.JOB_BATCH);
    }
}

Then in the configure method of the exporter you do this:

RecordFilter filter = new RecordFilter();
context.setFilter(filter);

That will filter out all JOB_BATCH events.


#4

Here is one: https://github.com/jwulf/zeebe-filtered-debug-exporter

And a docker-compose to start it (it’s on the 0.18 branch): https://github.com/zeebe-io/zeebe-docker-compose/blob/0.18/exporter-filtered-debug/docker-compose.yml

I haven’t tested it yet, I’ll get a chance to do that later tonight.

This should remove all JOB_BATCH events from the debug log.


Resolving a Job-related Incident need incident key
#5

Thanks, with your tips, I find it is about pollInterval when register worker in client , which has a default value 100ms in io.zeebe.client.impl.ZeebeClientBuilderImpl#defaultJobPollInterval