|
37 | 37 |
|
38 | 38 | MAX_JOB_NOPID = timedelta(seconds=10) |
39 | 39 | MAX_TASK_WAIT = 10 |
| 40 | +JOB_INFO_INTERVAL = 5 |
40 | 41 |
|
41 | 42 |
|
42 | 43 | def method_validate( |
@@ -568,12 +569,12 @@ def job_thread( |
568 | 569 | sys.exit() |
569 | 570 | elif ret.success and ret.data["running"] is False: |
570 | 571 | logger.warning( |
571 | | - "%s: task submitted %f s ago but not yet running", taskid, dt |
| 572 | + "%s: task was submitted %f s ago but is not yet running", taskid, dt |
572 | 573 | ) |
573 | 574 | pass |
574 | 575 | elif ret.success and "task" in ret.data and ret.data["task"] != task: |
575 | 576 | logger.warning( |
576 | | - "%s: task submitted %f s ago but other task running: %s", |
| 577 | + "%s: task was submitted %f s ago but another task is running: %s", |
577 | 578 | taskid, |
578 | 579 | dt, |
579 | 580 | ret.data["task"], |
@@ -677,7 +678,7 @@ def job_thread( |
677 | 678 | thread.crashed = True |
678 | 679 | sys.exit() |
679 | 680 | elif not ret.success: |
680 | | - logger.warning("%s: could not reset component: %s", component.role, ret.msg) |
| 681 | + logger.warning("%s: could not reset component %s", component.role, ret.msg) |
681 | 682 | else: |
682 | 683 | logger.info("%s: reset of component %s done", component.role, component.name) |
683 | 684 | req.close() |
@@ -753,29 +754,37 @@ def job_main_loop( |
753 | 754 |
|
754 | 755 | # wait until threads join or we're killed |
755 | 756 | snapshot = job.payload.settings.snapshot |
756 | | - t0 = time.perf_counter() |
| 757 | + tS = time.perf_counter() |
| 758 | + tD = tS |
757 | 759 | started_task_names = set() |
| 760 | + logger.debug("polling threads until completion") |
758 | 761 | while True: |
759 | 762 | tN = time.perf_counter() |
760 | | - if snapshot is not None and tN - t0 > snapshot.snapshot_interval: |
| 763 | + if snapshot is not None and tN - tS > snapshot.snapshot_interval: |
761 | 764 | logger.debug("creating snapshot") |
762 | 765 | merge_netcdfs(job, snapshot=True) |
763 | | - t0 += snapshot.snapshot_interval |
| 766 | + tS += snapshot.snapshot_interval |
764 | 767 |
|
765 | 768 | # Collect and push task names |
766 | 769 | for t in threads.values(): |
767 | 770 | if t.current_task is not None and t.current_task.task_name is not None: |
768 | 771 | started_task_names.add(t.current_task.task_name) |
769 | | - logger.debug("started task names are: %s", started_task_names) |
770 | 772 | for t in threads.values(): |
771 | 773 | t.started_task_names.update(started_task_names) |
772 | 774 | crashed = [t.crashed for t in threads.values()] |
773 | 775 | joined = [t.is_alive() is False or t.crashed for t in threads.values()] |
| 776 | + if tN - tD > JOB_INFO_INTERVAL: |
| 777 | + logger.info("started task names are: %s", started_task_names) |
| 778 | + logger.info("joined threads are: %s", joined) |
| 779 | + logger.info("crashed threads are: %s", crashed) |
| 780 | + tD += JOB_INFO_INTERVAL |
774 | 781 | if all(joined): |
775 | | - if any(crashed): |
776 | | - return 1 |
777 | | - else: |
778 | | - return None |
779 | | - else: |
780 | | - # We'd like to execute this loop exactly once every second |
781 | | - time.sleep(1.0 - tN % 1) |
| 782 | + break |
| 783 | + # We'd like to execute this loop exactly once every second |
| 784 | + time.sleep(1.0 - tN % 1) |
| 785 | + |
| 786 | + logger.info("all threads have joined") |
| 787 | + if any(crashed): |
| 788 | + return 1 |
| 789 | + else: |
| 790 | + return None |
0 commit comments