Changes between Version 3 and Version 4 of Workshops/JobCheckpointing/Examples/R


Ignore:
Timestamp:
04/08/2026 04:47:32 PM (3 months ago)
Author:
Carl Baribault
Comment:

Updated for use with checkpoint_submitter.sh

Legend:

Unmodified
Added
Removed
Modified

  • Workshops/JobCheckpointing/Examples/R

    v3 v4  
    11[[PageOutline]]
    2 = R Checkpointing Example - Under construction =
    3 
    4 '''This page is under construction to comply with the checkpoint submitter/runner implementation.'''
    5 
    6 == Checkpoint Runner ==
    7 
    8 See [wiki:Workshops/JobCheckpointing/Examples#CheckpointRunner Checkpoint Runner] for the contents of the job script file '''checkpoint_runner.sh'''.
    9 
    10 == R Checkpointing Application ==
    11 
    12 === checkpoint_signal_iter.R ===
     2= R Checkpointing Example =
     3
     4Here is an example of a checkpointing application implemented in R script.
     5
     6By default, the R checkpointing application behaves as follows.
     7
     8 * checkpointing every 20 application iterations (one second per iteration) and
     9 * running a total of 500 iterations.
     10
     11== Running the R checkpointing example with defaults ==
     12
     13To run the application on Cypress, perform the following.
     14
     151. Create your own versions of the following files in your current directory on Cypress. (For file editing with '''nano''' on Cypress, see [[https://wiki.hpc.tulane.edu/trac/wiki/cypress/FileEditingSoftware/Example|File Editing Example]].)
     16
     17 * [wiki://Workshops/JobCheckpointing/Examples#checkpoint_submitter.sh checkpoint_submitter.sh]
     18 * [wiki://Workshops/JobCheckpointing/Examples#checkpoint_runner.sh checkpoint_runner.sh]
     19 * [wiki://Workshops/JobCheckpointing/Examples#aggregate_usage.py aggregate_usage.py]
     20 * [wiki://Workshops/JobCheckpointing/Examples#plot_progress.py plot_progress.py]
     21
     222. Create your own version of the following R application script file '''checkpoint_signal_R.sh'''.
    1323
    1424{{{
    … …  
    6878}}}
    6979
    70 == Running R checkpointing example on Cypress ==
    71 
    72 To run the R checkpointing job example, defaulting to checkpointing every 20 application iterations and a total of 500 iterations, perform the following.
    73 
    74 1. Edit the files '''checkpoint_runner.sh''' and '''checkpoint_signal_iter.R''' as shown above in your current directory.
    75  For file editing with nano, etc., see [wiki:cypress/FileEditingSoftware/Example File Editing Example].
    76 
    77 2. Use the steps in the section [wiki:cypress/RunningRStudioWithSingularity#Alternativefortidyverse Alternative for tidyverse] for constructing a container image file '''tidyverse_latest.sif''' (or '''tidyverse_4.5.2.sif''' as in the following) for use with Singularity.
    78 
    79 3. Install the required R package '''sigterm''' via the following, substituting your own writable R library directory for <R_lib_path>. See [wiki:cypress/InstallingRPackages Installing R Packages on Cypress] for more information on using a writable R library directory.
     80
     813. Use the steps in the section [wiki:cypress/RunningRStudioWithSingularity#Alternativefortidyverse Alternative for tidyverse] for constructing a container image file '''tidyverse_latest.sif''' (or '''tidyverse_4.5.2.sif''' as in the following) for use with Singularity.
     82
     834. Install the required R package '''sigterm''' via the following, substituting your own writable R library directory for <R_lib_path>. See [wiki:cypress/InstallingRPackages Installing R Packages on Cypress] for more information on using a writable R library directory.
    8084
    8185{{{
    … …  
    9094}}}
    9195
    92 4. Submit the job via the following command.
    93 
    94 {{{
    95 [tulaneID@cypress1 ~]$APP_CMD="singularity exec tidyverse_4.5.2.sif Rscript checkpoint_signal_iter.R" MODULE_LIST="singularity/3.9.0" CKPT_PATH=state_iter_r.txt sbatch checkpoint_runner.sh
    96 }}}
    97 
    98 5. Monitor the job's output via the following command, substituting the job ID for <jobID>.
    99 
    100 {{{
    101 [tulaneID@cypress1 ~]$ tail -f log_<jobID>.*
    102 }}}
    103 
    104 6. Here are normal results for the output and error files, '''log_<jobID>.err''' and  '''log_<jobID>.out''', observing that the job cancelled and requeued itself many times. (Not all cancellations were captured in the error file.)
    105 
    106 {{{
    107 [tulaneID@cypress1 ~]$cat log_3300700.err
    108 slurmstepd: *** JOB 3300700 CANCELLED AT 2026-03-13T22:20:20 ***
    109 slurmstepd: *** JOB 3300700 CANCELLED AT 2026-03-13T22:28:00 ***
    110 }}}
    111  
    112 {{{
    113 [tulaneID@cypress1 ~]$cat log_3300700.out
    114 Info[20260313-22:18:18]: Start on cypress01-066; JOB_ID=3300700; RESTARTS=0
    115 Info[20260313-22:18:18]: Settings:
    116 Info[20260313-22:18:18]: MODULE_LIST=singularity/3.9.0
    117 Info[20260313-22:18:18]: APP_CMD=singularity exec tidyverse_4.5.2.sif Rscript checkpoint_signal_iter.R
    118 Info[20260313-22:18:18]: LAUNCH_MODE=direct
    119 Info[20260313-22:18:18]: SRUN_ARGS=-n 1
    120 Info[20260313-22:18:18]: TIME_LIMIT=00:03:00
    121 Info[20260313-22:18:18]: MARGIN_SEC=60
    122 Info[20260313-22:18:18]: CKPT_PATH=state_iter_r.txt
    123 Info[20260313-22:18:18]: CHECKPOINT_EVERY=20
    124 Info[20260313-22:18:18]: MAX_ITER=500
    125 Info[20260313-22:18:18]: MAX_RESTARTS=10
    126 === BEGIN JOB SNAPSHOT (scontrol) ===
    127 JobId=3300700 Name=ckpt_requeue_demo
    128    Priority=80808 Nice=0 Account=<groupID> QOS=normal
    129    JobState=RUNNING Reason=None Dependency=(null)
    130    Requeue=1 Restarts=0 BatchFlag=1 ExitCode=0:0
    131    RunTime=00:00:01 TimeLimit=00:03:00 TimeMin=N/A
    132    StartTime=2026-03-13T22:18:18 EndTime=2026-03-13T22:21:18
    133    Partition=centos7 AllocNode:Sid=cypress2:33768
    134 === END JOB SNAPSHOT (scontrol) ===
     965. Submit the job via the following command.
     97
     98{{{
     99[tulaneID@cypress1 ~]$APP_CMD="singularity exec tidyverse_4.5.2.sif Rscript checkpoint_signal_iter.R" \ MODULE_LIST="singularity/3.9.0" \
     100CKPT_PATH=state_iter_r.txt \
     101sbatch checkpoint_submitter.sh
     102}}}
     103
     1046. You can monitor job outputs of both the checkpoint_submitter.sh and the checkpoint_runner.sh jobs as they are updated by executing the following '''tail''' command using the '''-F''' option to retry once per second, then using Ctrl+C to exit the retry process entirely.
     105
     106{{{
     107[tulaneID@cypress1 ~]$ tail -F log*
     108}}}
     109
     110== Overriding the default settings ==
     111
     112To customize your workflow, see [wiki://Workshops/JobCheckpointing/Examples#Overridingdefaultsettings Overriding default settings] for overriding the default settings in the checkpoint submitter according to your needs.
     113
     114== Sample run outputs ==
     115
     116=== List of output files ===
     117
     118Here is a list of all output files from a sample run sorted by time, latest-to-earliest
     119
     120{{{
     121[tulaneID@cypress2 ~]$ls -lt *.csv *.err *.out *.png *.txt
     122-rw-r--r-- 1 tulaneID hpcstaff 52539 Apr  1 17:07 anomaly_stats_table.png
     123-rw-r--r-- 1 tulaneID hpcstaff  1399 Apr  1 17:07 log_submitter_3303072.out
     124-rw-r--r-- 1 tulaneID hpcstaff   468 Apr  1 17:07 anomaly_details.csv
     125-rw-r--r-- 1 tulaneID hpcstaff   635 Apr  1 17:07 log_submitter_3303072.err
     126-rw-r--r-- 1 tulaneID hpcstaff 52642 Apr  1 17:07 progress_with_anomalies.png
     127-rw-r--r-- 1 tulaneID hpcstaff 41081 Apr  1 17:07 resource_trend.png
     128-rw-r--r-- 1 tulaneID hpcstaff   510 Apr  1 17:07 worker_usage.csv
     129-rw-r--r-- 1 tulaneID hpcstaff   722 Apr  1 17:07 log_submitter_3303070.out
     130-rw-r--r-- 1 tulaneID hpcstaff    18 Apr  1 17:07 submitter_state.txt
     131-rw-r--r-- 1 tulaneID hpcstaff   888 Apr  1 17:04 log_runner_3303071.out
     132-rw-r--r-- 1 tulaneID hpcstaff     4 Apr  1 17:04 state_iter_r.txt
     133-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 17:04 log_runner_3303071.err
     134-rw-r--r-- 1 tulaneID hpcstaff   722 Apr  1 17:04 log_submitter_3303067.out
     135-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 17:04 log_submitter_3303070.err
     136-rw-r--r-- 1 tulaneID hpcstaff    40 Apr  1 17:04 worker_ids.txt
     137-rw-r--r-- 1 tulaneID hpcstaff  1036 Apr  1 17:03 log_runner_3303068.out
     138-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 17:01 log_runner_3303068.err
     139-rw-r--r-- 1 tulaneID hpcstaff   722 Apr  1 17:01 log_submitter_3303064.out
     140-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 17:01 log_submitter_3303067.err
     141-rw-r--r-- 1 tulaneID hpcstaff  1036 Apr  1 17:01 log_runner_3303065.out
     142-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 16:59 log_runner_3303065.err
     143-rw-r--r-- 1 tulaneID hpcstaff   722 Apr  1 16:59 log_submitter_3303062.out
     144-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 16:59 log_submitter_3303064.err
     145-rw-r--r-- 1 tulaneID hpcstaff  1036 Apr  1 16:58 log_runner_3303063.out
     146-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 16:56 log_runner_3303063.err
     147-rw-r--r-- 1 tulaneID hpcstaff   729 Apr  1 16:56 log_submitter_3303060.out
     148-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 16:56 log_submitter_3303062.err
     149-rw-r--r-- 1 tulaneID hpcstaff  1000 Apr  1 16:56 log_runner_3303061.out
     150-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 16:54 log_runner_3303061.err
     151-rw-r--r-- 1 tulaneID hpcstaff     0 Apr  1 16:54 log_submitter_3303060.err
     152
     153}}}
     154
     155=== Sample checkpoint submitter logs ===
     156
     157Here are the first and last instances from among the multiple log files generated by the sequence of jobs running the job script [wiki://Workshops/JobCheckpointing/Examples#checkpoint_submitter.sh checkpoint_submitter.sh].
     158
     159The first job in the sequence was submitted by the user, and all other jobs thereafter in that sequence were submitted by the job script itself via '''self-restarting'''.
     160
     161==== Listing of the initial checkpoint submitter log - starting workflow ====
     162
     163Here is the listing of the first log file, '''log_submitter_3303060.out''', generated by [wiki://Workshops/JobCheckpointing/Examples#checkpoint_submitter.sh checkpoint_submitter.sh] ending with the message "Submitter approaching timeout -> restarting self. Submitted batch job 3303142."
     164
     165{{{
     166[tulaneID@cypress2 ~]$cat log_submitter_3303060.out
     167Info[20260401-16:54:06]: Start on cypress01-066; JOBID=3303060
     168Info[20260401-16:54:06]: Submitter settings:
     169Info[20260401-16:54:06]: CKPT_PATH=state_iter_r.txt
     170Info[20260401-16:54:06]: MAX_ITER=500
     171Info[20260401-16:54:06]: RUNNER_SCRIPT=checkpoint_runner.sh
     172Info[20260401-16:54:06]: SUBMITTER_MARGIN_SEC=60
     173Info[20260401-16:54:06]: SUBMITTER_TIME_LIMIT=3:30
     174Info[20260401-16:54:06]: No previous state found; starting fresh.
     175Info[20260401-16:54:06]: Submitter cycle: 0
     176Info[20260401-16:54:06]: Current checkpoint iteration: 0
     177Info[20260401-16:54:06]: Submitted worker: 3303061
     178Info[20260401-16:54:06]: Waiting on worker 3303061
     179Info[20260401-16:56:46]: Submitter approaching timeout -> restarting self
     180Submitted batch job 3303062
     181}}}
     182
     183==== Listing of the final checkpoint submitter log - completed workflow ====
     184
     185Here is the listing of the final log file, '''log_submitter_3303072.out''', generated by [wiki://Workshops/JobCheckpointing/Examples#checkpoint_submitter.sh checkpoint_submitter.sh] ending with the message "Workflow complete. Exiting submitter."
     186
     187{{{
     188[tulaneID@cypress2 ~]$cat log_submitter_3303072.out
     189Info[20260401-17:07:08]: Start on cypress01-066; JOBID=3303072
     190Info[20260401-17:07:08]: Submitter settings:
     191Info[20260401-17:07:08]: CKPT_PATH=state_iter_r.txt
     192Info[20260401-17:07:08]: MAX_ITER=500
     193Info[20260401-17:07:08]: RUNNER_SCRIPT=checkpoint_runner.sh
     194Info[20260401-17:07:08]: SUBMITTER_MARGIN_SEC=60
     195Info[20260401-17:07:08]: SUBMITTER_TIME_LIMIT=3:30
     196Info[20260401-17:07:08]: Loaded state: submitter_cycle=5
     197Info[20260401-17:07:08]: Submitter cycle: 5
     198Info[20260401-17:07:08]: Current checkpoint iteration: 501
     199Info[20260401-17:07:08]: Reached MAX_ITER=500; running final analytics.
     200Info[20260401-17:07:08]: Running analytics aggregate_usage.py ...
     201Wrote worker_usage.csv
     202     JobID  ElapsedSeconds   TotalCPU  ... ReqMem       NodeList      State
     2030  3303061             121  00:03.487  ...  512Mn  cypress01-066     FAILED
     2041  3303063             121  00:03.506  ...  512Mn  cypress01-066     FAILED
     2052  3303065             121  00:03.502  ...  512Mn  cypress01-066     FAILED
     2063  3303068             121  00:03.484  ...  512Mn  cypress01-066     FAILED
     2074  3303071              27  00:03.478  ...  512Mn  cypress01-066  COMPLETED
     208
     209[5 rows x 9 columns]
     210Info[20260401-17:07:10]: Running analytics plot_progress.py ...
     211Saved progress_with_anomalies.png
     212Saved resource_trend.png
     213Saved anomaly_details.csv
     214Saved anomaly_stats_table.png
     215Info[20260401-17:07:14]: Workflow complete. Exiting submitter.
     216}}}
     217
     218=== Sample checkpoint runner logs ===
     219
     220Here are the first and last output logs of the sequence of jobs generated by the job script [wiki://Workshops/JobCheckpointing/Examples#checkpoint_runner.sh checkpoint_runner.sh].
     221
     222All of the jobs in that sequence were submitted by the [wiki://Workshops/JobCheckpointing/Examples#checkpoint_submitter.sh checkpoint_submitter.sh] job script.
     223
     224==== Listing of the initial checkpoint runner log - starting application ====
     225
     226Here is the listing of the intial log file, '''log_runner_3303061.out''', generated by the job script [wiki://Workshops/JobCheckpointing/Examples#checkpoint_runner.sh checkpoint_runner.sh] ending with message "Timeout + checkpoint advance detected (0->120)."
     227
     228{{{
     229[tulaneID@cypress2 ~]$cat log_runner_3303061.out
     230Info[20260401-16:54:06]: Start on cypress01-066; JOBID=3303061
     231Info[20260401-16:54:06]: Runner settings:
     232Info[20260401-16:54:06]: APP_CMD=singularity exec tidyverse_4.5.2.sif Rscript checkpoint_signal_iter.R
     233Info[20260401-16:54:06]: CHECKPOINT_EVERY=20
     234Info[20260401-16:54:06]: CKPT_PATH=state_iter_r.txt
     235Info[20260401-16:54:06]: LAUNCH_MODE=direct
     236Info[20260401-16:54:06]: MAX_ITER=500
     237Info[20260401-16:54:06]: MODULE_LIST=singularity/3.9.0
     238Info[20260401-16:54:06]: RUNNER_MARGIN_SEC=60
     239Info[20260401-16:54:06]: RUNNER_TIME_LIMIT=00:03:00
     240Info[20260401-16:54:06]: SRUN_ARGS=-n 1
     241Info[20260401-16:54:06]: Loading modules.
    135242R: Resuming from i=0 (every 20, MAX_ITER=500)
    136243[periodic/iter] saved i=20
    … …  
    139246[periodic/iter] saved i=80
    140247[periodic/iter] saved i=100
    141 R: SIGTERM detected — saving i=117 and exiting 99
    142 Info[20260313-22:20:19]: Program exit code (from timeout wrapper): 124
    143 Info[20260313-22:20:19]: Timeout TERM observed; checkpoint advanced (0->117). Requeueing...
    144 Info[20260313-22:20:19]: Requeued via scontrol.
    145 Info[20260313-22:20:58]: Start on cypress01-066; JOB_ID=3300700; RESTARTS=1
    146 Info[20260313-22:20:58]: Settings:
    147 Info[20260313-22:20:58]: MODULE_LIST=singularity/3.9.0
    148 Info[20260313-22:20:58]: APP_CMD=singularity exec tidyverse_4.5.2.sif Rscript checkpoint_signal_iter.R
    149 Info[20260313-22:20:58]: LAUNCH_MODE=direct
    150 Info[20260313-22:20:58]: SRUN_ARGS=-n 1
    151 Info[20260313-22:20:58]: TIME_LIMIT=00:03:00
    152 Info[20260313-22:20:58]: MARGIN_SEC=60
    153 Info[20260313-22:20:58]: CKPT_PATH=state_iter_r.txt
    154 Info[20260313-22:20:58]: CHECKPOINT_EVERY=20
    155 Info[20260313-22:20:58]: MAX_ITER=500
    156 Info[20260313-22:20:58]: MAX_RESTARTS=10
    157 === BEGIN JOB SNAPSHOT (scontrol) ===
    158 JobId=3300700 Name=ckpt_requeue_demo
    159    Priority=80808 Nice=0 Account=<groupID> QOS=normal
    160    JobState=RUNNING Reason=None Dependency=(null)
    161    Requeue=1 Restarts=1 BatchFlag=1 ExitCode=0:0
    162    RunTime=00:00:01 TimeLimit=00:03:00 TimeMin=N/A
    163    StartTime=2026-03-13T22:20:57 EndTime=2026-03-13T22:23:57
    164    Partition=centos7 AllocNode:Sid=cypress2:33768
    165 === END JOB SNAPSHOT (scontrol) ===
    166 R: Resuming from i=117 (every 20, MAX_ITER=500)
    167 [periodic/iter] saved i=120
    168 [periodic/iter] saved i=140
    169 [periodic/iter] saved i=160
    170 [periodic/iter] saved i=180
    171 [periodic/iter] saved i=200
    172 [periodic/iter] saved i=220
    173 R: SIGTERM detected — saving i=236 and exiting 99
    174 Info[20260313-22:22:59]: Program exit code (from timeout wrapper): 124
    175 Info[20260313-22:22:59]: Timeout TERM observed; checkpoint advanced (117->236). Requeueing...
    176 Info[20260313-22:22:59]: Requeued via scontrol.
    177 Info[20260313-22:23:29]: Start on cypress01-066; JOB_ID=3300700; RESTARTS=2
    178 Info[20260313-22:23:29]: Settings:
    179 Info[20260313-22:23:29]: MODULE_LIST=singularity/3.9.0
    180 Info[20260313-22:23:29]: APP_CMD=singularity exec tidyverse_4.5.2.sif Rscript checkpoint_signal_iter.R
    181 Info[20260313-22:23:29]: LAUNCH_MODE=direct
    182 Info[20260313-22:23:29]: SRUN_ARGS=-n 1
    183 Info[20260313-22:23:29]: TIME_LIMIT=00:03:00
    184 Info[20260313-22:23:29]: MARGIN_SEC=60
    185 Info[20260313-22:23:29]: CKPT_PATH=state_iter_r.txt
    186 Info[20260313-22:23:29]: CHECKPOINT_EVERY=20
    187 Info[20260313-22:23:29]: MAX_ITER=500
    188 Info[20260313-22:23:29]: MAX_RESTARTS=10
    189 === BEGIN JOB SNAPSHOT (scontrol) ===
    190 JobId=3300700 Name=ckpt_requeue_demo
    191    Priority=80808 Nice=0 Account=<groupID> QOS=normal
    192    JobState=RUNNING Reason=None Dependency=(null)
    193    Requeue=1 Restarts=2 BatchFlag=1 ExitCode=0:0
    194    RunTime=00:00:02 TimeLimit=00:03:00 TimeMin=N/A
    195    StartTime=2026-03-13T22:23:27 EndTime=2026-03-13T22:26:27
    196    Partition=centos7 AllocNode:Sid=cypress2:33768
    197 === END JOB SNAPSHOT (scontrol) ===
    198 R: Resuming from i=236 (every 20, MAX_ITER=500)
    199 [periodic/iter] saved i=240
    200 [periodic/iter] saved i=260
    201 [periodic/iter] saved i=280
    202 [periodic/iter] saved i=300
    203 [periodic/iter] saved i=320
    204 [periodic/iter] saved i=340
    205 R: SIGTERM detected — saving i=355 and exiting 99
    206 Info[20260313-22:25:30]: Program exit code (from timeout wrapper): 124
    207 Info[20260313-22:25:30]: Timeout TERM observed; checkpoint advanced (236->355). Requeueing...
    208 Info[20260313-22:25:30]: Requeued via scontrol.
    209 Info[20260313-22:25:59]: Start on cypress01-066; JOB_ID=3300700; RESTARTS=3
    210 Info[20260313-22:25:59]: Settings:
    211 Info[20260313-22:25:59]: MODULE_LIST=singularity/3.9.0
    212 Info[20260313-22:25:59]: APP_CMD=singularity exec tidyverse_4.5.2.sif Rscript checkpoint_signal_iter.R
    213 Info[20260313-22:25:59]: LAUNCH_MODE=direct
    214 Info[20260313-22:25:59]: SRUN_ARGS=-n 1
    215 Info[20260313-22:25:59]: TIME_LIMIT=00:03:00
    216 Info[20260313-22:25:59]: MARGIN_SEC=60
    217 Info[20260313-22:25:59]: CKPT_PATH=state_iter_r.txt
    218 Info[20260313-22:25:59]: CHECKPOINT_EVERY=20
    219 Info[20260313-22:25:59]: MAX_ITER=500
    220 Info[20260313-22:25:59]: MAX_RESTARTS=10
    221 === BEGIN JOB SNAPSHOT (scontrol) ===
    222 JobId=3300700 Name=ckpt_requeue_demo
    223    Priority=80808 Nice=0 Account=<groupID> QOS=normal
    224    JobState=RUNNING Reason=None Dependency=(null)
    225    Requeue=1 Restarts=3 BatchFlag=1 ExitCode=0:0
    226    RunTime=00:00:02 TimeLimit=00:03:00 TimeMin=N/A
    227    StartTime=2026-03-13T22:25:57 EndTime=2026-03-13T22:28:57
    228    Partition=centos7 AllocNode:Sid=cypress2:33768
    229 === END JOB SNAPSHOT (scontrol) ===
    230 R: Resuming from i=355 (every 20, MAX_ITER=500)
    231 [periodic/iter] saved i=360
    232 [periodic/iter] saved i=380
    233 [periodic/iter] saved i=400
    234 [periodic/iter] saved i=420
    235 [periodic/iter] saved i=440
    236 [periodic/iter] saved i=460
    237 R: SIGTERM detected — saving i=474 and exiting 99
    238 Info[20260313-22:28:00]: Program exit code (from timeout wrapper): 124
    239 Info[20260313-22:28:00]: Timeout TERM observed; checkpoint advanced (355->474). Requeueing...
    240 Info[20260313-22:28:00]: Requeued via scontrol.
    241 Info[20260313-22:28:19]: Start on cypress01-066; JOB_ID=3300700; RESTARTS=4
    242 Info[20260313-22:28:19]: Settings:
    243 Info[20260313-22:28:19]: MODULE_LIST=singularity/3.9.0
    244 Info[20260313-22:28:19]: APP_CMD=singularity exec tidyverse_4.5.2.sif Rscript checkpoint_signal_iter.R
    245 Info[20260313-22:28:19]: LAUNCH_MODE=direct
    246 Info[20260313-22:28:19]: SRUN_ARGS=-n 1
    247 Info[20260313-22:28:19]: TIME_LIMIT=00:03:00
    248 Info[20260313-22:28:19]: MARGIN_SEC=60
    249 Info[20260313-22:28:19]: CKPT_PATH=state_iter_r.txt
    250 Info[20260313-22:28:19]: CHECKPOINT_EVERY=20
    251 Info[20260313-22:28:19]: MAX_ITER=500
    252 Info[20260313-22:28:19]: MAX_RESTARTS=10
    253 === BEGIN JOB SNAPSHOT (scontrol) ===
    254 JobId=3300700 Name=ckpt_requeue_demo
    255    Priority=80808 Nice=0 Account=<groupID> QOS=normal
    256    JobState=RUNNING Reason=None Dependency=(null)
    257    Requeue=1 Restarts=4 BatchFlag=1 ExitCode=0:0
    258    RunTime=00:00:01 TimeLimit=00:03:00 TimeMin=N/A
    259    StartTime=2026-03-13T22:28:18 EndTime=2026-03-13T22:31:18
    260    Partition=centos7 AllocNode:Sid=cypress2:33768
    261 === END JOB SNAPSHOT (scontrol) ===
    262 R: Resuming from i=474 (every 20, MAX_ITER=500)
     248R: SIGTERM detected — saving i=119 and exiting 99
     249Info[20260401-16:56:07]: Program exit code (from timeout wrapper): 124
     250Info[20260401-16:56:07]: Timeout + checkpoint advance detected (0->119).
     251}}}
     252
     253==== Listing of the final checkpoint runner log - completed application ====
     254
     255Here is the listing of the final log file, '''log_runner_3303171.out''', generated by [wiki://Workshops/JobCheckpointing/Examples#checkpoint_runner.sh checkpoint_runner.sh] ending with message "Application finished all iterations."
     256
     257{{{
     258[tulaneID@cypress2 ~]$cat log_runner_3303071.out
     259Info[20260401-17:04:28]: Start on cypress01-066; JOBID=3303071
     260Info[20260401-17:04:28]: Runner settings:
     261Info[20260401-17:04:28]: APP_CMD=singularity exec tidyverse_4.5.2.sif Rscript checkpoint_signal_iter.R
     262Info[20260401-17:04:28]: CHECKPOINT_EVERY=20
     263Info[20260401-17:04:28]: CKPT_PATH=state_iter_r.txt
     264Info[20260401-17:04:28]: LAUNCH_MODE=direct
     265Info[20260401-17:04:28]: MAX_ITER=500
     266Info[20260401-17:04:28]: MODULE_LIST=singularity/3.9.0
     267Info[20260401-17:04:28]: RUNNER_MARGIN_SEC=60
     268Info[20260401-17:04:28]: RUNNER_TIME_LIMIT=00:03:00
     269Info[20260401-17:04:28]: SRUN_ARGS=-n 1
     270Info[20260401-17:04:28]: Loading modules.
     271R: Resuming from i=476 (every 20, MAX_ITER=500)
    263272[periodic/iter] saved i=480
    264273[periodic/iter] saved i=500
    265274Reached i=501 > 500; exiting 0
    266 Info[20260313-22:28:47]: Program exit code (from timeout wrapper): 0
    267 Info[20260313-22:28:47]: Completed.
    268 }}}
     275Info[20260401-17:04:55]: Program exit code (from timeout wrapper): 0
     276Info[20260401-17:04:55]: Application finished all iterations.
     277}}}
     278
     279=== Listings of post-workflow analysis output files ===
     280
     281The following is the complete, annotated listing of all the generated .csv and .txt files
     282
     283{{{
     284[tulaneID@cypress2 ~]$tail -n +1 *.csv *.txt
     285==> anomaly_details.csv <==
     286JobID,StartTime,ElapsedSeconds,MaxRSS_MiB,TimeZ,MemModZ,AnomalyType
     2873303061,2026-04-01 16:54:06,121.0,91.64047241210938,0.4999999999999999,0.0,none
     2883303063,2026-04-01 16:56:46,121.0,93.33038330078124,0.4999999999999999,0.0,none
     2893303065,2026-04-01 16:59:17,121.0,91.4154052734375,0.4999999999999999,0.0,none
     2903303068,2026-04-01 17:01:57,121.0,95.40939331054688,0.4999999999999999,0.0,none
     2913303071,2026-04-01 17:04:28,27.0,44.5709228515625,-2.0,10.857998043052838,memory
     292
     293==> worker_usage.csv <==
     294JobID,ElapsedSeconds,TotalCPU,MaxRSS,MaxRSS_bytes,MaxRSS_MiB,ReqMem,NodeList,State
     2953303061,121,00:03.487,96092K,96092000.0,91.64047241210938,512Mn,cypress01-066,FAILED
     2963303063,121,00:03.506,97864K,97864000.0,93.33038330078125,512Mn,cypress01-066,FAILED
     2973303065,121,00:03.502,95856K,95856000.0,91.4154052734375,512Mn,cypress01-066,FAILED
     2983303068,121,00:03.484,100044K,100044000.0,95.40939331054688,512Mn,cypress01-066,FAILED
     2993303071,27,00:03.478,46736K,46736000.0,44.5709228515625,512Mn,cypress01-066,COMPLETED
     300
     301==> state_iter_r.txt <==
     302501
     303
     304==> submitter_state.txt <==
     305submitter_cycle=5
     306
     307==> worker_ids.txt <==
     3083303061
     3093303063
     3103303065
     3113303068
     3123303071
     313}}}
     314
     315=== Post-workflow analysis plots ===
     316
     317==== Background ====
     318
     319For background on the following plots, see [wiki://Workshops/JobCheckpointing/Examples#Plottingexecutiontimeandmemoryusage Plotting execution time and memory usage].
     320
     321==== Table of anomalies, compute time and memory usage ====
     322
     323Here is the plot, '''anomaly_stats_table.png''', showing the table of anomalies, if any, from among all of the [wiki://Workshops/JobCheckpointing/Examples#checkpoint_runner.sh checkpoint_runner.sh] jobs.
     324
     325[[Image(R_anomaly_stats_table.png)]]
     326
     327==== Compute progress ====
     328
     329Here is the plot, '''progress_with_anomalies.png''', showing '''Checkpoint Progress''' and '''MaxRSS''' (SLURM max job memory usage) vs '''Wall Time'''.
     330
     331[[Image(R_progress_with_anomalies.png, width=800px)]]
     332
     333==== Execution time and memory usage trends ====
     334
     335Here is the plot, '''resource_trend.png''', showing '''Elapsed (time)''' and '''MaxRSS''' vs. '''Worker job index'''.
     336
     337[[Image(R_resource_trend.png, width=800px)]]