#CronJobs run multiple times in production

22 messages · Page 1 of 1 (latest)

wind stump
#

We have a single instance running in Google Cloud Run and the CronJobs are run in production (but not locally) three times.

There's multiple issues about this, but I haven't been able to find a solution and I am FAIRLY sure that it's not a PEBCAK-issue.

Eg.
https://github.com/nestjs/schedule/issues/454
https://github.com/nestjs/schedule/issues/445
"Why are cron jobs run at 3-4 times at..." here on #nestjs-help
"My cron runs 3 times in a row in a single" here on #nestjs-help
"Dynamic Crons are executed many times" here on #nestjs-help
"Cron Job Triggers multiple times" here on #nestjs-help
https://github.com/kelektiv/node-cron/issues/543
https://github.com/kelektiv/node-cron/issues/605
etc.

My app.module.ts looks like this:

@Module({
  imports: [
    ScheduleModule.forRoot(),
    TypeOrmModule.forRootAsync({
      inject: [ConfigService],
      useClass: TypeOrmConfigService,
    }),
    PollerModule,
  ],
})
export class AppModule implements NestModule {
  configure(consumer: MiddlewareConsumer) {
    consumer
      .apply(RequestPathHandlerMiddleware)
      .forRoutes({ path: '*', method: RequestMethod.ALL });
  }
}

The PollerModule has the PollerService that has the CronJobs:

@Module({
  imports: [FooModule, BarModule, BizModule],
  providers: [PollerService],
  controllers: [PollerWebhooksController],
})
export class PollerModule {}

PollerService:

@Injectable()
export class PollerService {
  @Cron(CronExpression.EVERY_5_MINUTES, {
    name: 'fooCronJob',
    disabled: process.env.NODE_ENV !== 'production',
    timeZone: 'Europe/Helsinki',
  })
  async fooJob() {
    console.log('I am run 3 times!')
  }
}

One of the issues recommended setting name, which fixed it for some, it did not for us. One suggestion was that the service should be only added to providers once, which it is. Additionally, the initialization scripts, onModuleInit() commands are ran only once, so there's only one instance running.

Any other ideas?

acoustic flower
#

Do you deploy using Dockerfile? Can you run the exact same container that runs in production locally?

wind stump
#

I just tried that, and the issue does not occur when ran locally via the Dockerfile, or when just running the built app directly via nest build

#

the Cloud Run instance has a single CPU and is limited to 1 instance (like said eg. onModuleInit is only ran once)

acoustic flower
#

Could you try with @Interval(300_000) instead of @Cron? Interval is implemented differently. This could tell us whether the issue is with the cron package or somewhere else.

wind stump
#

Sure, just a second, it takes around 5 mins to deploy

#

it's now deploying, so I'll get back on this in ~10

wind stump
#

@acoustic flower sadly @Interval shows the same issue in production, but only twice instead of 3 times.

image.png
#

eg. here we can see the same line of code running twice near simultaniously

image.png
#

Here you can see the initiatialization, only single messages

image.png
acoustic flower
#

Add log in the service constructor. You have single app instance, but could still have multiple class instances (having the service in ‘providers’ array in two modules)

wind stump
#

I'll try that out! Does it create another class instance if I inject the service to eg. a controller? as these are the only uses, and poller.module is only used in app module

image.png
acoustic flower
#

No, injecting to a controller shouldn't create a new instance. As long as your PollerModule is not some kind of dynamic module and the PollerService is in the default scope (and has no request-scoped dependency), that should be fine.

wind stump
#

Yeah, PollerModule is not dynamic and the service is in the default scope

acoustic flower
#

Good. Let's see what the constructor log says then.

wind stump
#

it gets only called once too

image.png
acoustic flower
wind stump
#

Yeah I am pretty much out of ideas too, I was thinking about trying out the dynamic cron jobs too and see if it would show something else but deadlines and stuff are closing in 😵‍💫. I am fairly sure the issue is in the underlying cron library, but cannot pinpoint the issue there either. Thanks for the help anyway, it was appriated a ton 🫡

wind stump
#

Umm hi, it's me again. In the PollerService, I had two methods with different Interval/CronJobs - when I removed the other one it correctly only ran the first method once 👀

# 
@Injectable()
export class PollerService {
  private readonly logger = new Logger(PollerService.name);
  constructor() {
    
  }

  @Interval(1000)
   cronOne() {
      this.logger.log(‘One’)
   }

   @Interval(2000)
   cronTwo() {
      this.logger.log(‘Two’);
   }
}

// logs: One, One, Two, Two


@Injectable()
export class PollerService {
  private readonly logger = new Logger(PollerService.name);
  constructor() {
    
  }

  @Interval(1000)
   cronOne() {
      this.logger.log(‘One’)
   }

   cronTwo() {
      this.logger.log(‘Two’);
   }
}

// logs: One
acoustic flower
#

I've just tested having 2 intervals in single service and it's working correctly in my setup. Nice find though.
This is a wild guess, but maybe it's compilation-related? Like, the build outputs the decorators in a weird way, so the intervals get registered twice? No idea how to debug that though.

I am fairly sure the issue is in the underlying cron library
I don't think it is, since @Interval and @Timeout decorators are implemented by @nestjs/scheduler using setInterval and setTimeout - they don't call the cron package in any way.

wind stump
#

I tried looking at the build output previously, but it correctly only showed two calls to the decorators

image.png