3. Scheduling module is recovering a running schedule?

Scheduling module is recovering a running schedule?

  • F

    On an irregular basis, JsReport (on-premise) is recovering a daily schedule that is already running and when it does that, it skips the next day. For example, I have a schedule named "MyScheduleName" that renders the "MyTemplateName" template at 04:25 UTC every day. No other schedules are running at this time, and below is the "reporter.log":

    2020-09-18T04:25:01.814Z - info: Starting rendering request 1133 (user: undefined)
2020-09-18T04:25:01.829Z - info: Rendering template { name: MyTemplateName, recipe: html, engine: handlebars, preview: false }
2020-09-18T04:25:33.047Z - info: Recovering task MyScheduleName
2020-09-18T04:25:33.484Z - info: Starting rendering request 1134 (user: undefined)
2020-09-18T04:25:33.499Z - info: Rendering template { name: MyTemplateName, recipe: html, engine: handlebars, preview: false }
2020-09-18T04:25:38.538Z - info: Rendering request 1133 finished in 36724 ms
2020-09-18T04:26:04.153Z - info: Rendering request 1134 finished in 30669 ms

    It is normal for this schedule to render in 30-36 seconds because of a beforeRender function call that retrieves data and perform complex calculations from a database. Note the log entry "Recovering task MyScheduleName". The schedule is still running, so I don't understand why it is being recovered. When this recovery happens, the report fails to schedule on the following day. (On 2020-09-19 at 4:25am, there are no log entries at all, and JsReport Studio shows that the schedule did not launch on that day. The next time the above schedule launched is on 2020-09-20 at 4:25am UTC. The CRON schedule is definitely daily.)

    This does not happen every day, but it happens enough and with other daily schedules to warrant this forum post. I see the same pattern in the "reporter.log". A recovery occurs while the daily schedule is running (between "Starting rendering request" and "Rendering request finished"), and if so, the report does not launch the following day. I don't mind the recovery due to the long render, but it's the fact that the report doesn't schedule the following day that is a problem for my organization.

    Any assistance is appreciated. If you need any additional examples or information from the on-premise installation, I'll be happy to supply it. Unfortunately, I cannot replicate this problem easily; it just seems to happen on an irregular basis. Thank you.

    0
  • administrators

    hi! what is your jsreport version? can you share the jsreport config you have? I think we can try to reproduce or analyze the case with the comments you have made, however, it will be much better if we try it with the same version and config you have.

    0
  • F

    The problem is occurring with JsReport 2.4 (we've been using it since its release). I am currently testing JsReport 2.10, but as mentioned earlier, the problem is difficult to replicate. Here is my config for JsReport 2.4:

    {
  "extensions": {
    "authentication": {
      "cookieSession": {
        "secret": "<your strong secret here>"
      },
      "admin": {
        "username": "admin",
        "password": "password"
      },
      "enabled": false
    },
    "chrome-pdf": {
      "launchOptions": {
        "args": ["--no-sandbox"]
      }
    },
    "fs-store": {
      "syncModifications": false
    },
    "html-embedded-in-docx": {
      "previewInOfficeOnline": false
    },
    "html-to-text": {
      "ignoreImage": true
    }, 
    "html-to-xlsx": {
      "previewInExcelOnline": false
    },
    "sample-template": {
      "createSamples": false
    },
    "scheduling": {
      "maxParallelJobs": 2
    },
    "scripts": {
      "timeout": 1200000,
      "strategy": "http-server"
    },
    "xlsx": {
      "previewInExcelOnline": false
    }
  },
  "httpPort": 5488,
  "store": {
    "provider": "fs"
  },
  "blobStorage": {
    "provider": "fs"
  },
  "logger": {
    "console": {
      "transport": "console",
      "level": "debug"
    },
    "file": {
      "transport": "file",
      "level": "info",
      "filename": "logs/reporter.log",
      "maxsize": 1000000,
      "maxFiles": 5 
    },
    "error": {
      "transport": "file",
      "level": "error",
      "filename": "logs/error.log",
      "maxsize": 1000000,
      "maxFiles": 5 
    }
  },
  "allowLocalFilesAccess": true,
  "templatingEngines": {
    "timeout": 120000,
    "strategy": "http-server",
    "numberOfWorkers": 3,
    "forkOptions": {
        "execArgv": ["--max-old-space-size=4096"]
    }
  },
  "chrome": {
    "timeout": 1200000
  },
  "express": {
    "inputRequestLimit": "200mb"
  }
}
    0
  • F

    Here is a recent log (schedule and template names changed). Multiple recoveries of a running schedule?

    2020-10-12T05:55:01.680Z - info: Starting rendering request 2090 (user: undefined)
2020-10-12T05:55:01.680Z - info: Rendering template { name: Template for MySchedule1, recipe: text, engine: handlebars, preview: false }
2020-10-12T06:00:53.585Z - info: Starting rendering request 2091 (user: undefined)
2020-10-12T06:01:04.630Z - info: Rendering template { name: Template for MySchedule2, recipe: html, engine: handlebars, preview: false }
2020-10-12T06:01:08.888Z - info: Recovering task MySchedule1
2020-10-12T06:01:08.904Z - info: Recovering task MySchedule2
2020-10-12T06:01:15.253Z - info: Recovering task MySchedule1
2020-10-12T06:01:15.253Z - info: Recovering task MySchedule2
2020-10-12T06:01:25.190Z - info: Recovering task MySchedule1
2020-10-12T06:01:25.190Z - info: Recovering task MySchedule2
2020-10-12T06:01:31.352Z - info: Recovering task MySchedule1
2020-10-12T06:01:31.384Z - info: Recovering task MySchedule2
2020-10-12T06:01:31.384Z - info: Recovering task MySchedule1
2020-10-12T06:01:31.384Z - info: Recovering task MySchedule2
2020-10-12T06:01:41.149Z - info: Recovering task MySchedule1
2020-10-12T06:01:41.149Z - info: Recovering task MySchedule2
2020-10-12T06:01:45.689Z - info: Recovering task MySchedule1
2020-10-12T06:01:45.689Z - info: Recovering task MySchedule2
2020-10-12T06:01:50.057Z - info: Recovering task MySchedule1
2020-10-12T06:01:50.057Z - info: Recovering task MySchedule2
2020-10-12T06:01:54.378Z - info: Recovering task MySchedule1
2020-10-12T06:01:54.394Z - info: Recovering task MySchedule2
2020-10-12T06:01:58.481Z - info: Recovering task MySchedule1
2020-10-12T06:01:58.481Z - info: Recovering task MySchedule2
2020-10-12T06:02:02.708Z - info: Recovering task MySchedule1
2020-10-12T06:02:02.708Z - info: Recovering task MySchedule2
2020-10-12T06:02:03.738Z - info: Recovering task MySchedule1
2020-10-12T06:02:03.738Z - info: Recovering task MySchedule2
2020-10-12T06:02:07.232Z - info: Recovering task MySchedule1
2020-10-12T06:02:07.248Z - info: Recovering task MySchedule2
2020-10-12T06:02:12.100Z - info: Recovering task MySchedule1
2020-10-12T06:02:12.100Z - info: Recovering task MySchedule2
2020-10-12T06:02:44.345Z - info: Starting rendering request 2092 (user: undefined)
2020-10-12T06:02:44.345Z - info: Starting rendering request 2093 (user: undefined)
2020-10-12T06:02:48.495Z - info: Rendering template { name: Template for MySchedule1, recipe: text, engine: handlebars, preview: false }
2020-10-12T06:02:48.495Z - info: Rendering template { name: Template for MySchedule2, recipe: html, engine: handlebars, preview: false }
2020-10-12T06:05:40.488Z - info: Rendering request 2093 finished in 176097 ms
2020-10-12T06:05:45.777Z - info: Rendering request 2091 finished in 292176 ms
2020-10-12T06:05:53.405Z - info: Rendering request 2090 finished in 651725 ms
2020-10-12T06:12:02.034Z - info: Rendering request 2092 finished in 557689 ms

    Both schedules have templates that use beforeRender function calls to retrieve data. Any assistance would be appreciated.

    0
  • administrators

    may I suggest that first, you try to use the 2.10 version? the bug is a bit tricky to reproduce and you are using a really old version, it can be the case that the most recent version already handles this case properly because there are a lot of changes in jsreport-scheduling since jsreport 2.4.0

    0

  • @fmmich I see you use the file system store, based on the config. Is this correct? Just there was such bug you describe in the mongodb store....
    If you use fs store, don't you run multiple jsreport instances against the single shared file system? Like with pm2 cluster mode for example.

    0
  • D

    I ran into this issue lately.

    I am running JSReport 3.7.1 in docker and with fs store.

    I have a scheduled report that takes takes in beforeRender more than 10 seconds to run.

    After 10 seconds jsreports starts recovering the currently running job and hell breaks loose. Seems that the ping-routine in the code is not behaving correctly.

    I checked the ping timestamp in the /app/data/tasks file and it seems that this is not updated at start of the scheduler run (at least not on the disk). And that is why it is not seeing the ping.

    I worked around this is issue by setting unconfigured config parameter (found in code):
    "extensions": {
    "scheduling": {
    "taskPingTimeout" : 3600000
    }
    }

    This will give enough time for the task to finish before it is trying to be recovered.

    0

  • Thank you for isolating the problem.
    I verify this is a bug, I've fixed it now and we will ship the fix with the next release.
    I apologize for the inconvenience.

    0
  • M

    Hi @jan_blaha , my team ran into this, but I believe we are running an old version before your change was made (3.4.1). Do you mind linking the commit or version where this was fixed?

    Thanks!

    0

  • Likely this commit https://github.com/jsreport/jsreport/commit/3873c1bf01d5c65db3df33f125c49464d90fde44
    And jsreport 3.8.0 https://github.com/jsreport/jsreport/releases/tag/3.8.0

    But recommended using the latest v4 of course...

    0
  • M

    Perfect! Thank you!

    Yes, we are planning on upgrading to 4, but I just wanted to have a bit more context on the issue. Appreciate the info!

    0
scheduling 3
Log in to reply
 

Looks like your connection to jsreport forum was lost, please wait while we try to reconnect.