00001
00002
00003 module ice_timers
00004
00005
00006
00007
00008
00009
00010
00011
00012
00013
00014
00015
00016
00017
00018
00019
00020
00021
00022 use ice_kinds_mod
00023 use ice_constants
00024 use ice_domain
00025 use ice_global_reductions
00026 use ice_exit
00027 use ice_fileunits, only: nu_diag, nu_timing
00028 use ice_communicate, only: my_task, master_task, get_num_procs, lprint_stats
00029 use ice_gather_scatter, only: gatherArray
00030
00031 implicit none
00032 private
00033 save
00034
00035
00036
00037 public :: init_ice_timers, &
00038 get_ice_timer, &
00039 ice_timer_clear, &
00040 ice_timer_start, &
00041 ice_timer_stop, &
00042 ice_timer_print, &
00043 ice_timer_print_all, &
00044 ice_timer_check
00045
00046
00047
00048
00049
00050
00051
00052
00053 integer (int_kind), public ::
00054 timer_total,
00055 timer_step,
00056 timer_dynamics,
00057 timer_advect,
00058 timer_column,
00059 timer_thermo,
00060 timer_sw,
00061 timer_ridge,
00062 timer_catconv,
00063 timer_couple,
00064 timer_readwrite,
00065 timer_diags,
00066 timer_hist,
00067 #ifdef CCSMCOUPLED
00068 timer_cplrecv, &
00069 timer_rcvsnd, &
00070 timer_cplsend, &
00071 timer_sndrcv, &
00072 #endif
00073 timer_bound
00074
00075
00076
00077
00078
00079
00080
00081
00082 integer (int_kind), parameter ::
00083 max_timers = 50
00084
00085 type timer_data
00086 character (char_len) ::
00087 name
00088
00089 logical (log_kind) ::
00090 in_use,
00091 node_started
00092
00093 integer (int_kind) ::
00094 num_blocks,
00095 num_nodes,
00096 num_starts,
00097 num_stops
00098
00099 real (dbl_kind) ::
00100 node_cycles1,
00101 node_cycles2
00102
00103 real (dbl_kind) ::
00104 node_accum_time
00105
00106 logical (log_kind), dimension(:), pointer ::
00107 block_started
00108
00109 real (dbl_kind), dimension(:), pointer ::
00110 block_cycles1,
00111 block_cycles2
00112
00113 real (dbl_kind), dimension(:), pointer ::
00114 block_accum_time
00115
00116 end type
00117
00118 type (timer_data), dimension(max_timers) ::
00119 all_timers
00120
00121 real (dbl_kind) ::
00122 clock_rate
00123
00124
00125
00126
00127 integer (int_kind), public :: timerRoot
00128
00129 real(dbl_kind), public :: all_ltime(max_timers)
00130 real(dbl_kind), allocatable :: all_gtime(:)
00131
00132
00133
00134
00135
00136 contains
00137
00138
00139
00140
00141
00142
00143 subroutine init_ice_timers
00144
00145
00146
00147
00148
00149
00150
00151
00152
00153
00154
00155
00156
00157
00158
00159
00160
00161 integer (int_kind) :: n
00162
00163
00164
00165
00166
00167
00168
00169 clock_rate = c1
00170
00171 timerRoot = min(distrb_info%nprocs-1,2)
00172
00173 do n=1,max_timers
00174 all_timers(n)%name = 'unknown_timer_name'
00175
00176 all_timers(n)%in_use = .false.
00177 all_timers(n)%node_started = .false.
00178
00179 all_timers(n)%num_blocks = 0
00180 all_timers(n)%num_nodes = 0
00181 all_timers(n)%num_starts = 0
00182 all_timers(n)%num_stops = 0
00183 all_timers(n)%node_cycles1 = c0
00184 all_timers(n)%node_cycles2 = c0
00185
00186 all_timers(n)%node_accum_time = c0
00187
00188 nullify(all_timers(n)%block_started)
00189 nullify(all_timers(n)%block_cycles1)
00190 nullify(all_timers(n)%block_cycles2)
00191 nullify(all_timers(n)%block_accum_time)
00192 end do
00193
00194 call get_ice_timer(timer_total, 'Total', nblocks,distrb_info%nprocs)
00195 #ifdef CCSMCOUPLED
00196 call get_ice_timer(timer_step, 'TimeLoop', nblocks,distrb_info%nprocs)
00197 #else
00198 call get_ice_timer(timer_step, 'Step', nblocks,distrb_info%nprocs)
00199 #endif
00200 call get_ice_timer(timer_dynamics, 'Dynamics', nblocks,distrb_info%nprocs)
00201 call get_ice_timer(timer_advect, 'Advection',nblocks,distrb_info%nprocs)
00202 call get_ice_timer(timer_column, 'Column', nblocks,distrb_info%nprocs)
00203 call get_ice_timer(timer_thermo, 'Thermo', nblocks,distrb_info%nprocs)
00204 call get_ice_timer(timer_sw, 'Shortwave',nblocks,distrb_info%nprocs)
00205 call get_ice_timer(timer_ridge, 'Ridging', nblocks,distrb_info%nprocs)
00206 call get_ice_timer(timer_catconv, 'Cat Conv', nblocks,distrb_info%nprocs)
00207 #ifndef CCSMCOUPLED
00208 call get_ice_timer(timer_couple, 'Coupling', nblocks,distrb_info%nprocs)
00209 #endif
00210 call get_ice_timer(timer_readwrite,'ReadWrite',nblocks,distrb_info%nprocs)
00211 call get_ice_timer(timer_diags, 'Diags ',nblocks,distrb_info%nprocs)
00212 call get_ice_timer(timer_hist, 'History ',nblocks,distrb_info%nprocs)
00213 call get_ice_timer(timer_bound, 'Bound', nblocks,distrb_info%nprocs)
00214 #ifdef CCSMCOUPLED
00215 call get_ice_timer(timer_cplrecv, 'Cpl-Imp', nblocks,distrb_info%nprocs)
00216 call get_ice_timer(timer_cplsend, 'Cpl-Exp', nblocks,distrb_info%nprocs)
00217 #endif
00218
00219
00220
00221
00222
00223 if(my_task .eq. timerRoot) then
00224 allocate(all_gtime(max_timers*distrb_info%nprocs))
00225 else
00226 allocate(all_gtime(1))
00227 endif
00228
00229
00230
00231
00232
00233 end subroutine init_ice_timers
00234
00235
00236
00237
00238
00239
00240 subroutine get_ice_timer(timer_id, name_choice, num_blocks, num_nodes)
00241
00242
00243
00244
00245
00246
00247
00248
00249
00250
00251 character (*), intent(in) ::
00252 name_choice
00253
00254 integer (int_kind), intent(in) ::
00255 num_nodes,
00256 num_blocks
00257
00258
00259
00260
00261
00262 integer (int_kind), intent(out) ::
00263 timer_id
00264
00265
00266
00267
00268
00269
00270
00271
00272
00273 integer (int_kind) ::
00274 n,
00275 srch_error
00276
00277
00278
00279
00280
00281
00282
00283 srch_error = 1
00284
00285 srch_loop: do n=1,max_timers
00286 if (.not. all_timers(n)%in_use) then
00287 srch_error = 0
00288 timer_id = n
00289
00290 all_timers(n)%name = ' '
00291 all_timers(n)%name = name_choice
00292 all_timers(n)%in_use = .true.
00293 all_timers(n)%num_blocks = num_blocks
00294 all_timers(n)%num_nodes = num_nodes
00295
00296 allocate(all_timers(n)%block_started (num_blocks), &
00297 all_timers(n)%block_cycles1 (num_blocks), &
00298 all_timers(n)%block_cycles2 (num_blocks), &
00299 all_timers(n)%block_accum_time(num_blocks))
00300
00301 all_timers(n)%block_started = .false.
00302 all_timers(n)%block_cycles1 = c0
00303 all_timers(n)%block_cycles2 = c0
00304 all_timers(n)%block_accum_time = c0
00305
00306 exit srch_loop
00307 endif
00308 end do srch_loop
00309
00310 if (srch_error /= 0) &
00311 call abort_ice('get_ice_timer: Exceeded maximum number of timers')
00312
00313
00314
00315
00316
00317 end subroutine get_ice_timer
00318
00319
00320
00321
00322
00323
00324 subroutine ice_timer_clear(timer_id)
00325
00326
00327
00328
00329
00330
00331
00332
00333
00334
00335
00336 integer (int_kind), intent(in) ::
00337 timer_id
00338
00339
00340
00341
00342
00343
00344
00345
00346
00347
00348 if (all_timers(timer_id)%in_use) then
00349 all_timers(timer_id)%node_started = .false.
00350 all_timers(timer_id)%num_starts = 0
00351 all_timers(timer_id)%num_stops = 0
00352 all_timers(timer_id)%node_cycles1 = c0
00353 all_timers(timer_id)%node_cycles2 = c0
00354
00355 all_timers(timer_id)%node_accum_time = c0
00356
00357 all_timers(timer_id)%block_started(:) = .false.
00358 all_timers(timer_id)%block_cycles1(:) = c0
00359 all_timers(timer_id)%block_cycles2(:) = c0
00360 all_timers(timer_id)%block_accum_time(:) = c0
00361 else
00362 call abort_ice &
00363 ('ice_timer_clear: attempt to reset undefined timer')
00364
00365 endif
00366
00367
00368
00369
00370 end subroutine ice_timer_clear
00371
00372
00373
00374
00375
00376
00377 subroutine ice_timer_start(timer_id, block_id)
00378
00379
00380
00381
00382
00383
00384
00385
00386
00387
00388
00389 integer (int_kind), intent(in) ::
00390 timer_id
00391
00392 integer (int_kind), intent(in), optional ::
00393 block_id
00394
00395
00396
00397
00398
00399
00400 double precision MPI_WTIME
00401 external MPI_WTIME
00402
00403
00404
00405
00406
00407
00408
00409
00410
00411 if (all_timers(timer_id)%in_use) then
00412
00413
00414
00415
00416
00417 if (present(block_id)) then
00418
00419
00420
00421 if (all_timers(timer_id)%block_started(block_id)) &
00422 call ice_timer_stop(timer_id, block_id)
00423
00424
00425
00426 all_timers(timer_id)%block_started(block_id) = .true.
00427 all_timers(timer_id)%block_cycles1(block_id) = MPI_WTIME()
00428
00429
00430
00431
00432
00433
00434
00435
00436 if (.not. all_timers(timer_id)%node_started) then
00437 all_timers(timer_id)%node_started = .true.
00438 all_timers(timer_id)%num_starts = 1
00439 all_timers(timer_id)%num_stops = 0
00440 all_timers(timer_id)%node_cycles1 = MPI_WTIME()
00441 else
00442 all_timers(timer_id)%num_starts = &
00443 all_timers(timer_id)%num_starts + 1
00444 endif
00445
00446
00447
00448
00449
00450
00451
00452 else
00453
00454
00455 if (all_timers(timer_id)%node_started) &
00456 call ice_timer_stop(timer_id)
00457
00458
00459
00460 all_timers(timer_id)%node_started = .true.
00461 all_timers(timer_id)%node_cycles1 = MPI_WTIME()
00462
00463 endif
00464 else
00465 call abort_ice &
00466 ('ice_timer_start: attempt to start undefined timer')
00467
00468 endif
00469
00470
00471
00472
00473 end subroutine ice_timer_start
00474
00475
00476
00477
00478
00479
00480 subroutine ice_timer_stop(timer_id, block_id)
00481
00482
00483
00484
00485
00486
00487
00488
00489
00490
00491 integer (int_kind), intent(in) ::
00492 timer_id
00493
00494 integer (int_kind), intent(in), optional ::
00495 block_id
00496
00497
00498
00499
00500
00501
00502 double precision MPI_WTIME
00503 external MPI_WTIME
00504
00505
00506
00507
00508
00509
00510
00511
00512
00513 real (dbl_kind) ::
00514 cycles1, cycles2
00515
00516
00517
00518
00519
00520
00521
00522 cycles2 = MPI_WTIME()
00523
00524
00525
00526
00527
00528
00529
00530 if (all_timers(timer_id)%in_use) then
00531
00532
00533
00534
00535
00536 if (present(block_id)) then
00537
00538 all_timers(timer_id)%block_started(block_id) = .false.
00539
00540 cycles1 = all_timers(timer_id)%block_cycles1(block_id)
00541 all_timers(timer_id)%block_accum_time(block_id) = &
00542 all_timers(timer_id)%block_accum_time(block_id) + &
00543 clock_rate*(cycles2 - cycles1)
00544
00545
00546
00547
00548
00549 cycles1 = all_timers(timer_id)%node_cycles1
00550
00551
00552
00553 all_timers(timer_id)%num_stops = &
00554 all_timers(timer_id)%num_stops + 1
00555
00556 if (all_timers(timer_id)%num_starts == &
00557 all_timers(timer_id)%num_stops) then
00558
00559 all_timers(timer_id)%node_started = .false.
00560 all_timers(timer_id)%node_accum_time = &
00561 all_timers(timer_id)%node_accum_time + &
00562 clock_rate*(cycles2 - cycles1)
00563
00564 all_timers(timer_id)%num_starts = 0
00565 all_timers(timer_id)%num_stops = 0
00566
00567 all_ltime(timer_id) = all_timers(timer_id)%node_accum_time
00568
00569 endif
00570
00571
00572
00573
00574
00575
00576
00577 else
00578
00579 all_timers(timer_id)%node_started = .false.
00580 cycles1 = all_timers(timer_id)%node_cycles1
00581
00582 all_timers(timer_id)%node_accum_time = &
00583 all_timers(timer_id)%node_accum_time + &
00584 clock_rate*(cycles2 - cycles1)
00585
00586 all_ltime(timer_id) = all_timers(timer_id)%node_accum_time
00587
00588 endif
00589 else
00590 call abort_ice &
00591 ('ice_timer_stop: attempt to stop undefined timer')
00592
00593 endif
00594
00595
00596
00597
00598 end subroutine ice_timer_stop
00599
00600
00601
00602
00603
00604
00605 subroutine ice_timer_print(timer_id,stats)
00606
00607
00608
00609
00610
00611
00612
00613
00614
00615
00616
00617 integer (int_kind), intent(in) ::
00618 timer_id
00619
00620 logical (log_kind), intent(in), optional ::
00621 stats
00622
00623
00624
00625
00626
00627
00628
00629
00630
00631
00632 integer (int_kind) ::
00633 n,icount,
00634 nBlocks
00635
00636 logical (log_kind) ::
00637 lrestart_timer
00638
00639
00640 real (dbl_kind) ::
00641 local_time,
00642 min_time,
00643 max_time,
00644 mean_time
00645
00646 character (41), parameter ::
00647 timer_format = "('Timer ',i3,': ',a20,f11.2,' seconds')"
00648
00649 character (49), parameter ::
00650 stats_fmt1 = "(' Timer stats (node): min = ',f11.2,' seconds')",
00651 stats_fmt2 = "(' max = ',f11.2,' seconds')",
00652 stats_fmt3 = "(' mean= ',f11.2,' seconds')",
00653 stats_fmt4 = "(' Timer stats(block): min = ',f11.2,' seconds')"
00654
00655
00656
00657
00658
00659
00660
00661
00662 if (all_timers(timer_id)%in_use) then
00663 if (all_timers(timer_id)%node_started) then
00664 call ice_timer_stop(timer_id)
00665 lrestart_timer = .true.
00666 else
00667 lrestart_timer = .false.
00668 endif
00669
00670
00671
00672
00673 if (my_task < all_timers(timer_id)%num_nodes) then
00674 local_time = all_timers(timer_id)%node_accum_time
00675 else
00676 local_time = c0
00677 endif
00678 max_time = global_maxval(local_time,distrb_info)
00679
00680 if (my_task == master_task) then
00681 write (nu_diag,timer_format) timer_id, &
00682 trim(all_timers(timer_id)%name),max_time
00683 endif
00684
00685 if (present(stats)) then
00686 if (stats) then
00687
00688
00689
00690 min_time = global_minval(local_time,distrb_info)
00691 mean_time = global_sum(local_time,distrb_info)/ &
00692 real(all_timers(timer_id)%num_nodes,kind=dbl_kind)
00693 if (my_task == master_task) then
00694 write (nu_diag,stats_fmt1) min_time
00695 write (nu_diag,stats_fmt2) max_time
00696 write (nu_diag,stats_fmt3) mean_time
00697 endif
00698
00699
00700
00701
00702 local_time = bignum
00703 do n=1,all_timers(timer_id)%num_blocks
00704 local_time = min(local_time, &
00705 all_timers(timer_id)%block_accum_time(n))
00706 end do
00707 min_time = global_minval(local_time,distrb_info)
00708 if (min_time == bignum) min_time = c0
00709
00710
00711
00712 local_time = -bignum
00713 do n=1,all_timers(timer_id)%num_blocks
00714 local_time = max(local_time, &
00715 all_timers(timer_id)%block_accum_time(n))
00716 end do
00717 max_time = global_maxval(local_time,distrb_info)
00718 if (max_time == -bignum) min_time = c0
00719
00720
00721
00722 local_time = c0
00723 nBlocks = all_timers(timer_id)%num_blocks
00724 do n=1,nBlocks
00725 local_time = local_time + &
00726 all_timers(timer_id)%block_accum_time(n)
00727 end do
00728 icount = global_sum(nBlocks, distrb_info)
00729 if (icount > 0) mean_time=global_sum(local_time,distrb_info)&
00730 /real(icount,kind=dbl_kind)
00731
00732 if (my_task == master_task) then
00733 write (nu_diag,stats_fmt4) min_time
00734 write (nu_diag,stats_fmt2) max_time
00735 write (nu_diag,stats_fmt3) mean_time
00736 endif
00737
00738 endif
00739 endif
00740
00741 if (lrestart_timer) call ice_timer_start(timer_id)
00742 else
00743 call abort_ice &
00744 ('ice_timer_print: attempt to print undefined timer')
00745
00746 endif
00747
00748
00749
00750
00751 end subroutine ice_timer_print
00752
00753
00754
00755
00756
00757
00758 subroutine ice_timer_print_all(stats)
00759
00760
00761
00762
00763
00764
00765
00766
00767
00768
00769
00770 logical (log_kind), intent(in), optional ::
00771 stats
00772
00773
00774
00775
00776
00777
00778
00779
00780
00781
00782 integer (int_kind) :: nprocs
00783
00784 integer (int_kind) :: n
00785
00786
00787
00788
00789
00790
00791
00792 if (my_task == master_task) then
00793 write(nu_diag,'(/,a19,/)') 'Timing information:'
00794 endif
00795
00796 do n=1,max_timers
00797 if (all_timers(n)%in_use) then
00798 if (present(stats)) then
00799 call ice_timer_print(n,stats)
00800 else
00801 call ice_timer_print(n)
00802 endif
00803 endif
00804 end do
00805
00806
00807
00808
00809 call gatherArray(all_gtime,all_ltime,max_timers,timerRoot)
00810
00811
00812
00813
00814 if(my_task == timerRoot) then
00815 if(lprint_stats) then
00816 nprocs = get_num_procs()
00817 open(nu_timing,file='timing.bin',recl=8*max_timers*nprocs, &
00818 form = 'unformatted', access = 'direct', status='unknown')
00819 write(nu_timing,rec=1) all_gtime
00820 close(nu_timing)
00821 endif
00822 endif
00823
00824
00825
00826
00827 end subroutine ice_timer_print_all
00828
00829
00830
00831
00832
00833
00834 subroutine ice_timer_check(timer_id,block_id)
00835
00836
00837
00838
00839
00840
00841
00842
00843
00844
00845
00846 integer (int_kind), intent(in) ::
00847 timer_id
00848
00849 integer (int_kind), intent(in), optional ::
00850 block_id
00851
00852
00853
00854
00855
00856
00857
00858
00859
00860
00861
00862
00863
00864
00865 if (present(block_id)) then
00866 call ice_timer_stop (timer_id,block_id)
00867 call ice_timer_start(timer_id,block_id)
00868 else
00869 call ice_timer_stop (timer_id)
00870 call ice_timer_start(timer_id)
00871 endif
00872
00873
00874
00875
00876 end subroutine ice_timer_check
00877
00878
00879
00880 end module ice_timers
00881
00882