Nightly Batch-Jobs

Uwe_Wahser · 25 January 2016 13:26

Dear all,

since we are doing nightly data-loads into DHIS2 with a 3rd party ETL-tool, we
are obliged to control the DHIS2 background jobs as much as possible via api to
avoid conflicts with the loading processes.

Although I turned of all of the batch-functionalities in Maintenance-Scheduling,
there is an error message every night at 2:00 in catalina.out: "Could not obtain
transaction-synchronized Session for current thread" (more at the end of this
mail)

The error message appears at a time, when my jobs are already through, and I
don't see any negative side aspects (getting a clean log would be nice, though).
But I'd need to know what else is scheduled in the background out-of-the-box,
how to stop it and how to trigger it via api, as I want to avoid locks, memory
shortages etc. due to colliding batches.

DHIS2, Version 22, Build 21765, Standard Ubuntu 14.04 & Oracle 8

Any hint would be appreciated,

Thanks a lot, Uwe

--- catalina.out ---
* ERROR 2016-01-25 02:00:00,015 Unexpected error occurred in scheduled task.
(TaskUtils.java [taskScheduler-8])
org.hibernate.HibernateException: Could not obtain transaction-synchronized
Session for current thread
        at
org.springframework.orm.hibernate4.SpringSessionContext.currentSession(SpringSessionContext.java:134)
        at
org.hibernate.internal.SessionFactoryImpl.getCurrentSession(SessionFactoryImpl.java:993)
        at
org.hisp.dhis.hibernate.HibernateGenericStore.getSharingCriteria(HibernateGenericStore.java:205)
        at
org.hisp.dhis.hibernate.HibernateGenericStore.getSharingCriteria(HibernateGenericStore.java:200)
        at
org.hisp.dhis.common.hibernate.HibernateIdentifiableObjectStore.getAllLeCreated(HibernateIdentifiableObjectStore.java:404)
        at
org.hisp.dhis.fileresource.DefaultFileResourceService.getOrphanedFileResources(DefaultFileResourceService.java:138)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
        at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:201)
        at com.sun.proxy.$Proxy78.getOrphanedFileResources(Unknown Source)
        at
org.hisp.dhis.fileresource.FileResourceCleanUpTask.run(FileResourceCleanUpTask.java:58)
        at
org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
        at
org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
        at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
--- catalina.out ---

Halvdan_Grelland · 25 January 2016 15:23

Hi,

The (failed) job you are seeing in the logs is an internal (!) cleanup task which is ran at 2AM every 24H. In short, the task is necessary maintenance which removes orphaned files (FileResources) which have been posted to the instance but are marked for deletion.

Normally this task would run at 2AM, check for any orphaned files and, if any are found, delete them (and their DB references). In most realistic cases we are talking about a very small number of deletions, and more often than not none; not really a ‘batch job’ as such.

Unfortunately there seems to be a bug with the implementation which causes the exception you’re seeing. I’ll have to look into that and get a fix out.

The good news, though, is that it’s entirely unproblematic to leave this as is for now. It is just a failed background task which consumes virtually no resources and dies immediately after execution start. It should not affect anything else, but if you are indeed using the file storage capabilities (for data values/tracker) in your instance you might theoretically experience orphaned files piling up in case of client side issues. These are easy to remove once there is a fix released, though, not to worry.

As for configuring the time at which this task is ran (or if it is ran at all) this is not in place yet but will be more flexible in future versions. As said, though, it really should not affect your use case at all.

Hope that answers your question. Thanks for reporting!

Halvdan Grelland, DHIS 2 Core developer

···

2016-01-25 14:26 GMT+01:00 Uwe Wahser uwe@wahser.de:

Dear all,

since we are doing nightly data-loads into DHIS2 with a 3rd party ETL-tool, we

are obliged to control the DHIS2 background jobs as much as possible via api to

avoid conflicts with the loading processes.

Although I turned of all of the batch-functionalities in Maintenance-Scheduling,

there is an error message every night at 2:00 in catalina.out: "Could not obtain

transaction-synchronized Session for current thread" (more at the end of this

mail)

The error message appears at a time, when my jobs are already through, and I

don’t see any negative side aspects (getting a clean log would be nice, though).

But I’d need to know what else is scheduled in the background out-of-the-box,

how to stop it and how to trigger it via api, as I want to avoid locks, memory

shortages etc. due to colliding batches.

DHIS2, Version 22, Build 21765, Standard Ubuntu 14.04 & Oracle 8

Any hint would be appreciated,

Thanks a lot, Uwe

— catalina.out —

ERROR 2016-01-25 02:00:00,015 Unexpected error occurred in scheduled task.

(TaskUtils.java [taskScheduler-8])

org.hibernate.HibernateException: Could not obtain transaction-synchronized

Session for current thread
    at
org.springframework.orm.hibernate4.SpringSessionContext.currentSession(SpringSessionContext.java:134)
    at
org.hibernate.internal.SessionFactoryImpl.getCurrentSession(SessionFactoryImpl.java:993)
    at
org.hisp.dhis.hibernate.HibernateGenericStore.getSharingCriteria(HibernateGenericStore.java:205)
    at
org.hisp.dhis.hibernate.HibernateGenericStore.getSharingCriteria(HibernateGenericStore.java:200)
    at
org.hisp.dhis.common.hibernate.HibernateIdentifiableObjectStore.getAllLeCreated(HibernateIdentifiableObjectStore.java:404)
    at
org.hisp.dhis.fileresource.DefaultFileResourceService.getOrphanedFileResources(DefaultFileResourceService.java:138)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

    at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)

    at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:201)
    at com.sun.proxy.$Proxy78.getOrphanedFileResources(Unknown Source)

    at
org.hisp.dhis.fileresource.FileResourceCleanUpTask.run(FileResourceCleanUpTask.java:58)
    at
org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
    at
org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
    at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)

    at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
— catalina.out —

Mailing list: https://launchpad.net/~dhis2-users

Post to : dhis2-users@lists.launchpad.net

Unsubscribe : https://launchpad.net/~dhis2-users

More help : https://help.launchpad.net/ListHelp

Uwe_Wahser · 25 January 2016 15:54

Hi Halvdan,

thanks for the quick response and thanks for looking at it, although it doesn't
really sound dangerous to my setting.

Between the lines I understand that this is the only internally scheduled job,
or are any others to be aware of (cache deletion, index rebuilds etc.)?

As you are planning to make it more flexible it might be worthwhile to make it
available as an api-endpoint for external triggering and include a deselect into
the scheduling options as there might be people who want to upload files via api
- I would imagine that cleaning up while uploading might cause some problems ...

Regards, Uwe

···

Halvdan Grelland <halvdanhg@gmail.com> hat am 25. Januar 2016 um 18:23
geschrieben:

Hi,

The (failed) job you are seeing in the logs is an internal (!) cleanup task
which is ran at 2AM every 24H. In short, the task is necessary maintenance
which removes orphaned files (FileResources) which have been posted to the
instance but are marked for deletion.

Normally this task would run at 2AM, check for any orphaned files and, if
any are found, delete them (and their DB references). In most realistic
cases we are talking about a very small number of deletions, and more often
than not none; not really a 'batch job' as such.

Unfortunately there seems to be a bug with the implementation which causes
the exception you're seeing. I'll have to look into that and get a fix out.

The good news, though, is that it's entirely unproblematic to leave this as
is for now. It is just a failed background task which consumes virtually no
resources and dies immediately after execution start. It should not affect
anything else, but if you are indeed using the file storage capabilities
(for data values/tracker) in your instance you might theoretically
experience orphaned files piling up in case of client side issues. These
are easy to remove once there is a fix released, though, not to worry.

As for configuring the time at which this task is ran (or if it is ran at
all) this is not in place yet but will be more flexible in future versions.
As said, though, it really should not affect your use case at all.

Hope that answers your question. Thanks for reporting!

Halvdan Grelland, DHIS 2 Core developer

2016-01-25 14:26 GMT+01:00 Uwe Wahser <uwe@wahser.de>:

> Dear all,
>
> since we are doing nightly data-loads into DHIS2 with a 3rd party
> ETL-tool, we
> are obliged to control the DHIS2 background jobs as much as possible via
> api to
> avoid conflicts with the loading processes.
>
> Although I turned of all of the batch-functionalities in
> Maintenance-Scheduling,
> there is an error message every night at 2:00 in catalina.out: "Could not
> obtain
> transaction-synchronized Session for current thread" (more at the end of
> this
> mail)
>
> The error message appears at a time, when my jobs are already through, and
> I
> don't see any negative side aspects (getting a clean log would be nice,
> though).
> But I'd need to know what else is scheduled in the background
> out-of-the-box,
> how to stop it and how to trigger it via api, as I want to avoid locks,
> memory
> shortages etc. due to colliding batches.
>
> DHIS2, Version 22, Build 21765, Standard Ubuntu 14.04 & Oracle 8
>
> Any hint would be appreciated,
>
> Thanks a lot, Uwe
>
> --- catalina.out ---
> * ERROR 2016-01-25 02:00:00,015 Unexpected error occurred in scheduled
> task.
> (TaskUtils.java [taskScheduler-8])
> org.hibernate.HibernateException: Could not obtain transaction-synchronized
> Session for current thread
> at
>
> org.springframework.orm.hibernate4.SpringSessionContext.currentSession(SpringSessionContext.java:134)
> at
>
> org.hibernate.internal.SessionFactoryImpl.getCurrentSession(SessionFactoryImpl.java:993)
> at
>
> org.hisp.dhis.hibernate.HibernateGenericStore.getSharingCriteria(HibernateGenericStore.java:205)
> at
>
> org.hisp.dhis.hibernate.HibernateGenericStore.getSharingCriteria(HibernateGenericStore.java:200)
> at
>
> org.hisp.dhis.common.hibernate.HibernateIdentifiableObjectStore.getAllLeCreated(HibernateIdentifiableObjectStore.java:404)
> at
>
> org.hisp.dhis.fileresource.DefaultFileResourceService.getOrphanedFileResources(DefaultFileResourceService.java:138)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
>
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
>
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at
>
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at
>
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:201)
> at com.sun.proxy.$Proxy78.getOrphanedFileResources(Unknown Source)
> at
>
> org.hisp.dhis.fileresource.FileResourceCleanUpTask.run(FileResourceCleanUpTask.java:58)
> at
>
> org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
> at
>
> org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
>
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> at
>
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> at
>
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> --- catalina.out ---
>
> _______________________________________________
> Mailing list: https://launchpad.net/~dhis2-users
> Post to : dhis2-users@lists.launchpad.net
> Unsubscribe : https://launchpad.net/~dhis2-users
> More help : https://help.launchpad.net/ListHelp
>

Halvdan_Grelland · 25 January 2016 16:00

No problem.

I believe it is the only one, but I wouldn’t bet on it until Lars confirms it.

If and when it is to be made configurable it would be available in the API, yes, we are doing this for pretty much everything we do nowadays. The thing is, though, that as this really is only a system-internal job there is not real benefit to exposing the configuration completely, but I do see the use case for being able to disable (or reschedule) it on demand.

Collision with current uploads is a non-issue as we’re only dealing with objects which are so-and-so old (current or recent uploads will not be affected). We wouldn’t attempt to clean up a file which has just been put in staging.

···

2016-01-25 16:54 GMT+01:00 Uwe Wahser uwe@wahser.de:

Hi Halvdan,

thanks for the quick response and thanks for looking at it, although it doesn’t

really sound dangerous to my setting.

Between the lines I understand that this is the only internally scheduled job,

or are any others to be aware of (cache deletion, index rebuilds etc.)?

As you are planning to make it more flexible it might be worthwhile to make it

available as an api-endpoint for external triggering and include a deselect into

the scheduling options as there might be people who want to upload files via api

I would imagine that cleaning up while uploading might cause some problems …

Regards, Uwe

Halvdan Grelland halvdanhg@gmail.com hat am 25. Januar 2016 um 18:23

geschrieben:

Hi,

The (failed) job you are seeing in the logs is an internal (!) cleanup task

which is ran at 2AM every 24H. In short, the task is necessary maintenance

which removes orphaned files (FileResources) which have been posted to the

instance but are marked for deletion.

Normally this task would run at 2AM, check for any orphaned files and, if

any are found, delete them (and their DB references). In most realistic

cases we are talking about a very small number of deletions, and more often

than not none; not really a ‘batch job’ as such.

Unfortunately there seems to be a bug with the implementation which causes

the exception you’re seeing. I’ll have to look into that and get a fix out.

The good news, though, is that it’s entirely unproblematic to leave this as

is for now. It is just a failed background task which consumes virtually no

resources and dies immediately after execution start. It should not affect

anything else, but if you are indeed using the file storage capabilities

(for data values/tracker) in your instance you might theoretically

experience orphaned files piling up in case of client side issues. These

are easy to remove once there is a fix released, though, not to worry.

As for configuring the time at which this task is ran (or if it is ran at

all) this is not in place yet but will be more flexible in future versions.

As said, though, it really should not affect your use case at all.

Hope that answers your question. Thanks for reporting!

Halvdan Grelland, DHIS 2 Core developer

2016-01-25 14:26 GMT+01:00 Uwe Wahser uwe@wahser.de:

Dear all,

since we are doing nightly data-loads into DHIS2 with a 3rd party

ETL-tool, we

are obliged to control the DHIS2 background jobs as much as possible via

api to

avoid conflicts with the loading processes.

Although I turned of all of the batch-functionalities in

Maintenance-Scheduling,

there is an error message every night at 2:00 in catalina.out: "Could not

obtain

transaction-synchronized Session for current thread" (more at the end of

this

mail)

The error message appears at a time, when my jobs are already through, and

I

don’t see any negative side aspects (getting a clean log would be nice,

though).

But I’d need to know what else is scheduled in the background

out-of-the-box,

how to stop it and how to trigger it via api, as I want to avoid locks,

memory

shortages etc. due to colliding batches.

DHIS2, Version 22, Build 21765, Standard Ubuntu 14.04 & Oracle 8

Any hint would be appreciated,

Thanks a lot, Uwe

— catalina.out —

ERROR 2016-01-25 02:00:00,015 Unexpected error occurred in scheduled

task.

(TaskUtils.java [taskScheduler-8])

org.hibernate.HibernateException: Could not obtain transaction-synchronized

Session for current thread
    at
org.springframework.orm.hibernate4.SpringSessionContext.currentSession(SpringSessionContext.java:134)
    at
org.hibernate.internal.SessionFactoryImpl.getCurrentSession(SessionFactoryImpl.java:993)
    at
org.hisp.dhis.hibernate.HibernateGenericStore.getSharingCriteria(HibernateGenericStore.java:205)
    at
org.hisp.dhis.hibernate.HibernateGenericStore.getSharingCriteria(HibernateGenericStore.java:200)
    at
org.hisp.dhis.common.hibernate.HibernateIdentifiableObjectStore.getAllLeCreated(HibernateIdentifiableObjectStore.java:404)
    at
org.hisp.dhis.fileresource.DefaultFileResourceService.getOrphanedFileResources(DefaultFileResourceService.java:138)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:201)
    at com.sun.proxy.$Proxy78.getOrphanedFileResources(Unknown Source)
    at
org.hisp.dhis.fileresource.FileResourceCleanUpTask.run(FileResourceCleanUpTask.java:58)
    at
org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
    at
org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
    at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
— catalina.out —

Mailing list: https://launchpad.net/~dhis2-users

Post to : dhis2-users@lists.launchpad.net

Unsubscribe : https://launchpad.net/~dhis2-users

More help : https://help.launchpad.net/ListHelp