ballerina-platform / ballerina-distribution

Apache License 2.0
155 stars 192 forks source link

Intermittent Failure in publish release workflow on BBE verification #5780

Open sahanHe opened 1 year ago

sahanHe commented 1 year ago

Description:

The publish release workflow fails for the 2201.4.2 release with a output verification error in task BBEs with the following log.

Failed due to output did not match. Line 10: Apr 27, 2023 3:23:32 PM org.quartz.impl.StdSchedulerFactory instantiate
Failed due to output did not match. Line 11: INFO: Using default implementation for ThreadExecutor
Failed due to output did not match. Line 12: Apr 27, 2023 3:23:32 PM org.quartz.core.SchedulerSignalerImpl <init>
Failed due to output did not match. Line 13: INFO: Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
Failed due to output did not match. Line 14: Apr 27, 2023 3:23:32 PM org.quartz.core.QuartzScheduler <init>
Failed due to output did not match. Line 15: INFO: Quartz Scheduler v.2.3.2 created.
Failed due to output did not match. Line 16: Apr 27, 2023 3:23:32 PM org.quartz.simpl.RAMJobStore initialize
Failed due to output did not match. Line 17: INFO: RAMJobStore initialized.
Failed due to output did not match. Line 18: Apr 27, 2023 3:23:32 PM org.quartz.core.QuartzScheduler initialize
Failed due to output did not match. Line 19: INFO: Scheduler meta-data: Quartz Scheduler (v2.3.2) 'QuartzScheduler' with instanceId 'NON_CLUSTERED'
Failed due to output did not match. Line 20: Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
Failed due to output did not match. Line 21: NOT STARTED.
Failed due to output did not match. Line 22: Currently in standby mode.
Failed due to output did not match. Line 23: Number of jobs executed: 0
Failed due to output did not match. Line 24: Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 5 threads.
Failed due to output did not match. Line 25: Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.
Failed due to output did not match. Line 26: Apr 27, 2023 3:23:32 PM org.quartz.impl.StdSchedulerFactory instantiate
Failed due to output did not match. Line 27: INFO: Quartz scheduler 'QuartzScheduler' initialized from an externally provided properties instance.
Failed due to output did not match. Line 28: Apr 27, 2023 3:23:32 PM org.quartz.impl.StdSchedulerFactory instantiate
Failed due to output did not match. Line 29: INFO: Quartz scheduler version: 2.3.2
Failed due to output did not match. Line 30: Apr 27, 2023 3:23:32 PM org.quartz.core.QuartzScheduler start
Failed due to output did not match. Line 31: INFO: Scheduler QuartzScheduler_$_NON_CLUSTERED started.
Created new package 'test'.
Building example 'task-frequency-job-execution'

This can be viewed here

Steps to reproduce: Observed while running the publish release workflow for 2201.4.2

Affected Versions: Balerina distribution 2201.4.2

kalaiyarasiganeshalingam commented 1 year ago

The task module disabled all logs by resetting the logger manager. Hence, Could't logs other module logs when using task operation.

import ballerina/http;
import ballerina/io;
import ballerina/lang.runtime;
import ballerina/task;

type Album readonly & record {|
    string title;
    string artist;
|};

class Job {

    *task:Job;
    int i = 1;

    public function execute() {
        self.i += 1;
        io:println("MyCounter: ", self.i);
    }

    isolated function init(int i) {
        self.i = i;
    }
}

service /info on new http:Listener(9095) {

    resource function get albums(http:Request req) returns Album[]|error {
        http:Client albumEP = check new ("localhost:9090");
        task:JobId id = check task:scheduleJobRecurByFrequency(new Job(0), 1);
        runtime:sleep(5);
        Album[] albums = check albumEP->forward("/albums", req);
        return albums;
    }
}

Therefore, the task module was improved to enable logs excluding quartz logs. This fix has been tested. It works as expected. And, all the builds are passed without any errors except the release action build. But, the release builds produce some quartz logs intermittently.

anupama-pathirage commented 1 year ago

@kalaiyarasiganeshalingam do we know why relaease build produce some quartz logs intermittently?

@ThisaruGuruge / @keizer619 FYA please

kalaiyarasiganeshalingam commented 1 year ago

We couldn't figure out the actual reason as we couldn't reproduce it locally with the given fix.

When I remove all the fixes, I am able to reproduce the error locally.

May 02, 2023 4:41:06 PM org.quartz.impl.StdSchedulerFactory instantiate
INFO: Using default implementation for ThreadExecutor
May 02, 2023 4:41:06 PM org.quartz.core.SchedulerSignalerImpl <init>
INFO: Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
May 02, 2023 4:41:06 PM org.quartz.core.QuartzScheduler <init>
INFO: Quartz Scheduler v.2.3.2 created.
May 02, 2023 4:41:06 PM org.quartz.simpl.RAMJobStore initialize
INFO: RAMJobStore initialized.
May 02, 2023 4:41:06 PM org.quartz.core.QuartzScheduler initialize
INFO: Scheduler meta-data: Quartz Scheduler (v2.3.2) 'QuartzScheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 5 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

May 02, 2023 4:41:06 PM org.quartz.impl.StdSchedulerFactory instantiate
INFO: Quartz scheduler 'QuartzScheduler' initialized from an externally provided properties instance.
May 02, 2023 4:41:06 PM org.quartz.impl.StdSchedulerFactory instantiate
INFO: Quartz scheduler version: 2.3.2
May 02, 2023 4:41:06 PM org.quartz.core.QuartzScheduler start
INFO: Scheduler QuartzScheduler_$_NON_CLUSTERED started.
MyCounter: 1
MyCounter: 2
MyCounter: 3
MyCounter: 4
MyCounter: 5