Web2py scheduler stalls uWSGI actions #3

New Issue

2017-09-17T22:57:55+02:00

Disassembler commented

2017-09-17 22:57:55 +02:00

(Migrated from git.spotter.cz)

Steps to reproduce

Configure Sahana Eden scheduler as an uWSGI mule using mule = run_scheduler.py
Stop / restart uWSGI instance

Expected behaviour

root@debian:~# time systemctl restart uwsgi

real    0m1.189s
user    0m0.000s
sys     0m0.000s

Observed behaviour

Any stop/restart action takes 30 seconds more than actually needed.

root@debian:~# time systemctl restart uwsgi

real    0m30.214s
user    0m0.000s
sys     0m0.000s

### Steps to reproduce 1. Configure Sahana Eden scheduler as an uWSGI mule using `mule = run_scheduler.py` 2. Stop / restart uWSGI instance ### Expected behaviour ``` root@debian:~# time systemctl restart uwsgi real 0m1.189s user 0m0.000s sys 0m0.000s ``` ### Observed behaviour Any stop/restart action takes 30 seconds more than actually needed. ``` root@debian:~# time systemctl restart uwsgi real 0m30.214s user 0m0.000s sys 0m0.000s ```

Disassembler commented

2017-09-20 12:16:20 +02:00

(Migrated from git.spotter.cz)

The problem seems to be that the web2py gluon scheduler does not close transactions immediately.

2017-09-20 11:51:53.233 CEST [3121] sahana@sahana LOG:  statement: COMMIT
2017-09-20 11:51:53.235 CEST [3121] sahana@sahana LOG:  statement: BEGIN
2017-09-20 11:51:53.235 CEST [3121] sahana@sahana LOG:  statement: SELECT  scheduler_task.id, scheduler_task.application_name, scheduler_task.task_name, scheduler_task.group_name, scheduler_task.status, scheduler_task.function_name, scheduler_task.uuid, scheduler_task.args, scheduler_task.vars, scheduler_task.enabled, scheduler_task.start_time, scheduler_task.next_run_time, scheduler_task.stop_time, scheduler_task.repeats, scheduler_task.retry_failed, scheduler_task.period, scheduler_task.prevent_drift, scheduler_task.timeout, scheduler_task.sync_output, scheduler_task.times_run, scheduler_task.times_failed, scheduler_task.last_run_time, scheduler_task.assigned_worker_name FROM scheduler_task WHERE ((scheduler_task.assigned_worker_name = 'debian#3120') AND (scheduler_task.status = 'ASSIGNED')) ORDER BY scheduler_task.next_run_time LIMIT 1 OFFSET 0;

2017-09-20 11:51:53.247 CEST [3123] sahana@sahana LOG:  statement: BEGIN
2017-09-20 11:51:53.247 CEST [3123] sahana@sahana LOG:  statement: SELECT  scheduler_worker.id, scheduler_worker.worker_name, scheduler_worker.first_heartbeat, scheduler_worker.last_heartbeat, scheduler_worker.status, scheduler_worker.is_ticker, scheduler_worker.group_names, scheduler_worker.worker_stats FROM scheduler_worker WHERE (scheduler_worker.worker_name = 'debian#3120');
2017-09-20 11:51:53.250 CEST [3123] sahana@sahana LOG:  statement: UPDATE scheduler_worker SET status='ACTIVE',last_heartbeat='2017-09-20 11:51:53',worker_stats='{"status": "ACTIVE", "errors": 0, "workers": 1, "queue": 0, "empty_runs": 10, "sleep": 3, "distribution": {"main": {"workers": [{"c": 0, "name": "debian#3120"}]}}, "total": 0}' WHERE (scheduler_worker.worker_name = 'debian#3120');
2017-09-20 11:51:53.251 CEST [3123] sahana@sahana LOG:  statement: COMMIT

The first transaction gets commited on the next run. When the application shuts down, there is no next run, therefore some components (not sure which yet, but it's likely not PostgreSQL itself) waits 30s and cuts off the transaction with

2017-09-20 12:09:31.451 CEST [3121] sahana@sahana LOG:  unexpected EOF on client connection with an open transaction

The problem seems to be that the web2py gluon scheduler does not close transactions immediately. ``` 2017-09-20 11:51:53.233 CEST [3121] sahana@sahana LOG: statement: COMMIT 2017-09-20 11:51:53.235 CEST [3121] sahana@sahana LOG: statement: BEGIN 2017-09-20 11:51:53.235 CEST [3121] sahana@sahana LOG: statement: SELECT scheduler_task.id, scheduler_task.application_name, scheduler_task.task_name, scheduler_task.group_name, scheduler_task.status, scheduler_task.function_name, scheduler_task.uuid, scheduler_task.args, scheduler_task.vars, scheduler_task.enabled, scheduler_task.start_time, scheduler_task.next_run_time, scheduler_task.stop_time, scheduler_task.repeats, scheduler_task.retry_failed, scheduler_task.period, scheduler_task.prevent_drift, scheduler_task.timeout, scheduler_task.sync_output, scheduler_task.times_run, scheduler_task.times_failed, scheduler_task.last_run_time, scheduler_task.assigned_worker_name FROM scheduler_task WHERE ((scheduler_task.assigned_worker_name = 'debian#3120') AND (scheduler_task.status = 'ASSIGNED')) ORDER BY scheduler_task.next_run_time LIMIT 1 OFFSET 0; 2017-09-20 11:51:53.247 CEST [3123] sahana@sahana LOG: statement: BEGIN 2017-09-20 11:51:53.247 CEST [3123] sahana@sahana LOG: statement: SELECT scheduler_worker.id, scheduler_worker.worker_name, scheduler_worker.first_heartbeat, scheduler_worker.last_heartbeat, scheduler_worker.status, scheduler_worker.is_ticker, scheduler_worker.group_names, scheduler_worker.worker_stats FROM scheduler_worker WHERE (scheduler_worker.worker_name = 'debian#3120'); 2017-09-20 11:51:53.250 CEST [3123] sahana@sahana LOG: statement: UPDATE scheduler_worker SET status='ACTIVE',last_heartbeat='2017-09-20 11:51:53',worker_stats='{"status": "ACTIVE", "errors": 0, "workers": 1, "queue": 0, "empty_runs": 10, "sleep": 3, "distribution": {"main": {"workers": [{"c": 0, "name": "debian#3120"}]}}, "total": 0}' WHERE (scheduler_worker.worker_name = 'debian#3120'); 2017-09-20 11:51:53.251 CEST [3123] sahana@sahana LOG: statement: COMMIT ``` The first transaction gets commited on the next run. When the application shuts down, there is no next run, therefore some components (not sure which yet, but it's likely not PostgreSQL itself) waits 30s and cuts off the transaction with ``` 2017-09-20 12:09:31.451 CEST [3121] sahana@sahana LOG: unexpected EOF on client connection with an open transaction ```

Disassembler commented

2017-09-20 13:30:55 +02:00

(Migrated from git.spotter.cz)

changed title from {-Sahana-} scheduler stalls uWSGI actions to {+Web2py+} scheduler stalls uWSGI actions

changed title from **{-Sahana-} scheduler stalls uWSGI actions** to **{+Web2py+} scheduler stalls uWSGI actions**

Disassembler commented

2017-09-20 13:31:04 +02:00

(Migrated from git.spotter.cz)

Opened issue #1769 in upstream.

Opened issue [#1769](https://github.com/web2py/web2py/issues/1769) in upstream.

Disassembler commented

2017-09-20 13:31:10 +02:00