console and log output improvements
[alexxy/gromacs.git] / src / mdlib / gmx_wallcycle.c
1 /*
2  * This file is part of the GROMACS molecular simulation package.
3  *
4  * Copyright (c) 1991-2000, University of Groningen, The Netherlands.
5  * Copyright (c) 2001-2008, The GROMACS development team,
6  * check out http://www.gromacs.org for more information.
7  * Copyright (c) 2012, by the GROMACS development team, led by
8  * David van der Spoel, Berk Hess, Erik Lindahl, and including many
9  * others, as listed in the AUTHORS file in the top-level source
10  * directory and at http://www.gromacs.org.
11  *
12  * GROMACS is free software; you can redistribute it and/or
13  * modify it under the terms of the GNU Lesser General Public License
14  * as published by the Free Software Foundation; either version 2.1
15  * of the License, or (at your option) any later version.
16  *
17  * GROMACS is distributed in the hope that it will be useful,
18  * but WITHOUT ANY WARRANTY; without even the implied warranty of
19  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
20  * Lesser General Public License for more details.
21  *
22  * You should have received a copy of the GNU Lesser General Public
23  * License along with GROMACS; if not, see
24  * http://www.gnu.org/licenses, or write to the Free Software Foundation,
25  * Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301  USA.
26  *
27  * If you want to redistribute modifications to GROMACS, please
28  * consider that scientific software is very special. Version
29  * control is crucial - bugs must be traceable. We will be happy to
30  * consider code for inclusion in the official distribution, but
31  * derived work must not be called official GROMACS. Details are found
32  * in the README & COPYING files - if they are missing, get the
33  * official version at http://www.gromacs.org.
34  *
35  * To help us fund GROMACS development, we humbly ask that you cite
36  * the research papers on the package. Check out http://www.gromacs.org.
37  */
38
39
40 #ifdef HAVE_CONFIG_H
41 #include <config.h>
42 #endif
43
44 #include <string.h>
45 #include "gmx_wallcycle.h"
46 #include "gmx_cyclecounter.h"
47 #include "smalloc.h"
48 #include "gmx_fatal.h"
49 #include "md_logging.h"
50 #include "string2.h"
51
52 #ifdef GMX_LIB_MPI
53 #include <mpi.h>
54 #endif
55 #ifdef GMX_THREAD_MPI
56 #include "tmpi.h"
57 #endif
58
59 /* DEBUG_WCYCLE adds consistency checking for the counters.
60  * It checks if you stop a counter different from the last
61  * one that was opened and if you do nest too deep.
62  */
63 /* #define DEBUG_WCYCLE */
64
65 typedef struct
66 {
67     int          n;
68     gmx_cycles_t c;
69     gmx_cycles_t start;
70     gmx_cycles_t last;
71 } wallcc_t;
72
73 typedef struct gmx_wallcycle
74 {
75     wallcc_t     *wcc;
76     /* variables for testing/debugging */
77     gmx_bool         wc_barrier;
78     wallcc_t     *wcc_all;
79     int          wc_depth;
80 #ifdef DEBUG_WCYCLE
81 #define DEPTH_MAX 6
82     int          counterlist[DEPTH_MAX];
83     int          count_depth;
84 #endif
85     int          ewc_prev;
86     gmx_cycles_t cycle_prev;
87     gmx_large_int_t   reset_counters;
88 #ifdef GMX_MPI
89     MPI_Comm     mpi_comm_mygroup;
90 #endif
91     int          nthreads_pp;
92     int          nthreads_pme;
93 #ifdef GMX_CYCLE_SUBCOUNTERS
94     wallcc_t     *wcsc;
95 #endif
96     double       *cycles_sum;
97 } gmx_wallcycle_t_t;
98
99 /* Each name should not exceed 19 characters */
100 static const char *wcn[ewcNR] =
101 { "Run", "Step", "PP during PME", "Domain decomp.", "DD comm. load",
102   "DD comm. bounds", "Vsite constr.", "Send X to PME", "Neighbor search", "Launch GPU ops.",
103   "Comm. coord.", "Born radii", "Force", "Wait + Comm. F", "PME mesh",
104   "PME redist. X/F", "PME spread/gather", "PME 3D-FFT", "PME 3D-FFT Comm.", "PME solve",
105   "PME wait for PP", "Wait + Recv. PME F", "Wait GPU nonlocal", "Wait GPU local", "NB X/F buffer ops.",
106   "Vsite spread", "Write traj.", "Update", "Constraints", "Comm. energies",
107   "Enforced rotation", "Add rot. forces", "Test" };
108
109 static const char *wcsn[ewcsNR] =
110 { "DD redist.", "DD NS grid + sort", "DD setup comm.",
111   "DD make top.", "DD make constr.", "DD top. other",
112   "NS grid local", "NS grid non-loc.", "NS search local", "NS search non-loc.",
113   "Bonded F", "Nonbonded F", "Ewald F correction",
114   "NB X buffer ops.", "NB F buffer ops."
115 };
116
117 gmx_bool wallcycle_have_counter(void)
118 {
119   return gmx_cycles_have_counter();
120 }
121
122 gmx_wallcycle_t wallcycle_init(FILE *fplog,int resetstep,t_commrec *cr, 
123                                int nthreads_pp, int nthreads_pme)
124 {
125     gmx_wallcycle_t wc;
126     
127     
128     if (!wallcycle_have_counter())
129     {
130         return NULL;
131     }
132
133     snew(wc,1);
134
135     wc->wc_barrier          = FALSE;
136     wc->wcc_all             = NULL;
137     wc->wc_depth            = 0;
138     wc->ewc_prev            = -1;
139     wc->reset_counters      = resetstep;
140     wc->nthreads_pp         = nthreads_pp;
141     wc->nthreads_pme        = nthreads_pme;
142     wc->cycles_sum          = NULL;
143
144 #ifdef GMX_MPI
145     if (PAR(cr) && getenv("GMX_CYCLE_BARRIER") != NULL)
146     {
147         if (fplog) 
148         {
149             fprintf(fplog,"\nWill call MPI_Barrier before each cycle start/stop call\n\n");
150         }
151         wc->wc_barrier = TRUE;
152         wc->mpi_comm_mygroup = cr->mpi_comm_mygroup;
153     }
154 #endif
155
156     snew(wc->wcc,ewcNR);
157     if (getenv("GMX_CYCLE_ALL") != NULL)
158     {
159         if (fplog) 
160         {
161             fprintf(fplog,"\nWill time all the code during the run\n\n");
162         }
163         snew(wc->wcc_all,ewcNR*ewcNR);
164     }
165
166 #ifdef GMX_CYCLE_SUBCOUNTERS
167     snew(wc->wcsc,ewcsNR);
168 #endif
169
170 #ifdef DEBUG_WCYCLE
171     wc->count_depth = 0;
172 #endif
173
174     return wc;
175 }
176
177 void wallcycle_destroy(gmx_wallcycle_t wc)
178 {
179     if (wc == NULL)
180     {
181         return;
182     }
183     
184     if (wc->wcc != NULL)
185     {
186         sfree(wc->wcc);
187     }
188     if (wc->wcc_all != NULL)
189     {
190         sfree(wc->wcc_all);
191     }
192 #ifdef GMX_CYCLE_SUBCOUNTERS
193     if (wc->wcsc != NULL)
194     {
195         sfree(wc->wcsc);
196     }
197 #endif
198     sfree(wc);
199 }
200
201 static void wallcycle_all_start(gmx_wallcycle_t wc,int ewc,gmx_cycles_t cycle)
202 {
203     wc->ewc_prev = ewc;
204     wc->cycle_prev = cycle;
205 }
206
207 static void wallcycle_all_stop(gmx_wallcycle_t wc,int ewc,gmx_cycles_t cycle)
208 {
209     wc->wcc_all[wc->ewc_prev*ewcNR+ewc].n += 1;
210     wc->wcc_all[wc->ewc_prev*ewcNR+ewc].c += cycle - wc->cycle_prev;
211 }
212
213
214 #ifdef DEBUG_WCYCLE
215 static void debug_start_check(gmx_wallcycle_t wc, int ewc)
216 {
217     /* fprintf(stderr,"wcycle_start depth %d, %s\n",wc->count_depth,wcn[ewc]); */
218
219     if (wc->count_depth < 0 || wc->count_depth >= DEPTH_MAX)
220     {
221         gmx_fatal(FARGS,"wallcycle counter depth out of range: %d",
222                   wc->count_depth);
223     }
224     wc->counterlist[wc->count_depth] = ewc;
225     wc->count_depth++;
226 }
227
228 static void debug_stop_check(gmx_wallcycle_t wc, int ewc)
229 {
230     wc->count_depth--;
231
232     /* fprintf(stderr,"wcycle_stop depth %d, %s\n",wc->count_depth,wcn[ewc]); */
233
234     if (wc->count_depth < 0)
235     {
236         gmx_fatal(FARGS,"wallcycle counter depth out of range when stopping %s: %d",wcn[ewc],wc->count_depth);
237     }
238     if (wc->counterlist[wc->count_depth] != ewc)
239     {
240         gmx_fatal(FARGS,"wallcycle mismatch at stop, start %s, stop %s",
241                   wcn[wc->counterlist[wc->count_depth]],wcn[ewc]);
242     }
243 }
244 #endif
245
246 void wallcycle_start(gmx_wallcycle_t wc, int ewc)
247 {
248     gmx_cycles_t cycle;
249
250     if (wc == NULL)
251     {
252         return;
253     }
254
255 #ifdef GMX_MPI
256     if (wc->wc_barrier)
257     {
258         MPI_Barrier(wc->mpi_comm_mygroup);
259     }
260 #endif
261
262 #ifdef DEBUG_WCYCLE
263     debug_start_check(wc,ewc);
264 #endif
265
266     cycle = gmx_cycles_read();
267     wc->wcc[ewc].start = cycle;
268     if (wc->wcc_all != NULL)
269     {
270         wc->wc_depth++;
271         if (ewc == ewcRUN)
272         {
273             wallcycle_all_start(wc,ewc,cycle);
274         }
275         else if (wc->wc_depth == 3)
276         {
277             wallcycle_all_stop(wc,ewc,cycle);
278         }
279     }
280 }
281
282 void wallcycle_start_nocount(gmx_wallcycle_t wc, int ewc)
283 {
284     if (wc == NULL)
285     {
286         return;
287     }
288
289     wallcycle_start(wc, ewc);
290     wc->wcc[ewc].n--;
291 }
292
293 double wallcycle_stop(gmx_wallcycle_t wc, int ewc)
294 {
295     gmx_cycles_t cycle,last;
296     
297     if (wc == NULL)
298     {
299         return 0;
300     }
301     
302 #ifdef GMX_MPI
303     if (wc->wc_barrier)
304     {
305         MPI_Barrier(wc->mpi_comm_mygroup);
306     }
307 #endif
308
309 #ifdef DEBUG_WCYCLE
310     debug_stop_check(wc,ewc);
311 #endif
312     
313     cycle = gmx_cycles_read();
314     last = cycle - wc->wcc[ewc].start;
315     wc->wcc[ewc].c += last;
316     wc->wcc[ewc].n++;
317     if (wc->wcc_all)
318     {
319         wc->wc_depth--;
320         if (ewc == ewcRUN)
321         {
322             wallcycle_all_stop(wc,ewc,cycle);
323         }
324         else if (wc->wc_depth == 2)
325         {
326             wallcycle_all_start(wc,ewc,cycle);
327         }
328     }
329
330     return last;
331 }
332
333 void wallcycle_reset_all(gmx_wallcycle_t wc)
334 {
335     int i;
336
337     if (wc == NULL)
338     {
339         return;
340     }
341
342     for(i=0; i<ewcNR; i++)
343     {
344         wc->wcc[i].n = 0;
345         wc->wcc[i].c = 0;
346     }
347     if (wc->wcc_all)
348     {
349         for(i=0; i<ewcNR*ewcNR; i++)
350         {
351             wc->wcc_all[i].n = 0;
352             wc->wcc_all[i].c = 0;
353         }
354     }
355 #ifdef GMX_CYCLE_SUBCOUNTERS
356     for (i=0; i<ewcsNR; i++)
357     {
358         wc->wcsc[i].n = 0;
359         wc->wcsc[i].c = 0;
360     }
361 #endif
362 }
363
364 static gmx_bool is_pme_counter(int ewc)
365 {
366     return (ewc >= ewcPMEMESH && ewc <= ewcPMEWAITCOMM);
367 }
368
369 static gmx_bool is_pme_subcounter(int ewc)
370 {
371     return (ewc >= ewcPME_REDISTXF && ewc < ewcPMEWAITCOMM);
372 }
373
374 void wallcycle_sum(t_commrec *cr, gmx_wallcycle_t wc)
375 {
376     wallcc_t *wcc;
377     double *cycles;
378     double cycles_n[ewcNR+ewcsNR],buf[ewcNR+ewcsNR],*cyc_all,*buf_all;
379     int    i,j;
380     int    nsum;
381
382     if (wc == NULL)
383     {
384         return;
385     }
386
387     snew(wc->cycles_sum,ewcNR+ewcsNR);
388     cycles = wc->cycles_sum;
389
390     wcc = wc->wcc;
391
392     for(i=0; i<ewcNR; i++)
393     {
394         if (is_pme_counter(i) || (i==ewcRUN && cr->duty == DUTY_PME))
395         {
396             wcc[i].c *= wc->nthreads_pme;
397
398             if (wc->wcc_all)
399             {
400                 for(j=0; j<ewcNR; j++)
401                 {
402                     wc->wcc_all[i*ewcNR+j].c *= wc->nthreads_pme;
403                 }
404             }
405         }
406         else
407         {
408             wcc[i].c *= wc->nthreads_pp;
409
410             if (wc->wcc_all)
411             {
412                 for(j=0; j<ewcNR; j++)
413                 {
414                     wc->wcc_all[i*ewcNR+j].c *= wc->nthreads_pp;
415                 }
416             }
417         }
418     }
419
420     if (wcc[ewcDDCOMMLOAD].n > 0)
421     {
422         wcc[ewcDOMDEC].c -= wcc[ewcDDCOMMLOAD].c;
423     }
424     if (wcc[ewcDDCOMMBOUND].n > 0)
425     {
426         wcc[ewcDOMDEC].c -= wcc[ewcDDCOMMBOUND].c;
427     }
428     if (wcc[ewcPME_FFTCOMM].n > 0)
429     {
430         wcc[ewcPME_FFT].c -= wcc[ewcPME_FFTCOMM].c;
431     }
432
433     if (cr->npmenodes == 0)
434     {
435         /* All nodes do PME (or no PME at all) */
436         if (wcc[ewcPMEMESH].n > 0)
437         {
438             wcc[ewcFORCE].c -= wcc[ewcPMEMESH].c;
439         }
440     }
441     else
442     {
443         /* The are PME-only nodes */
444         if (wcc[ewcPMEMESH].n > 0)
445         {
446             /* This must be a PME only node, calculate the Wait + Comm. time */
447             wcc[ewcPMEWAITCOMM].c = wcc[ewcRUN].c - wcc[ewcPMEMESH].c;
448         }
449     }
450     
451     /* Store the cycles in a double buffer for summing */
452     for(i=0; i<ewcNR; i++)
453     {
454         cycles_n[i] = (double)wcc[i].n;
455         cycles[i]   = (double)wcc[i].c;
456     }
457     nsum = ewcNR;
458 #ifdef GMX_CYCLE_SUBCOUNTERS
459     for(i=0; i<ewcsNR; i++)
460     {
461         wc->wcsc[i].c *= wc->nthreads_pp;
462         cycles_n[ewcNR+i] = (double)wc->wcsc[i].n;
463         cycles[ewcNR+i]   = (double)wc->wcsc[i].c;
464     }
465     nsum += ewcsNR;
466 #endif   
467     
468 #ifdef GMX_MPI
469     if (cr->nnodes > 1)
470     {
471         MPI_Allreduce(cycles_n,buf,nsum,MPI_DOUBLE,MPI_MAX,
472                       cr->mpi_comm_mysim);
473         for(i=0; i<ewcNR; i++)
474         {
475             wcc[i].n = (int)(buf[i] + 0.5);
476         }
477 #ifdef GMX_CYCLE_SUBCOUNTERS
478         for(i=0; i<ewcsNR; i++)
479         {
480             wc->wcsc[i].n = (int)(buf[ewcNR+i] + 0.5);
481         }
482 #endif   
483
484         MPI_Allreduce(cycles,buf,nsum,MPI_DOUBLE,MPI_SUM,
485                       cr->mpi_comm_mysim);
486         for(i=0; i<nsum; i++)
487         {
488             cycles[i] = buf[i];
489         }
490
491         if (wc->wcc_all != NULL)
492         {
493             snew(cyc_all,ewcNR*ewcNR);
494             snew(buf_all,ewcNR*ewcNR);
495             for(i=0; i<ewcNR*ewcNR; i++)
496             {
497                 cyc_all[i] = wc->wcc_all[i].c;
498             }
499             MPI_Allreduce(cyc_all,buf_all,ewcNR*ewcNR,MPI_DOUBLE,MPI_SUM,
500                           cr->mpi_comm_mysim);
501             for(i=0; i<ewcNR*ewcNR; i++)
502             {
503                 wc->wcc_all[i].c = buf_all[i];
504             }
505             sfree(buf_all);
506             sfree(cyc_all);
507         }
508     }
509 #endif
510 }
511
512 static void print_cycles(FILE *fplog, double c2t, const char *name, 
513                          int nnodes_tot,int nnodes, int nthreads,
514                          int n, double c, double tot)
515 {
516     char num[11];
517     char thstr[6];
518     double wallt;
519   
520     if (c > 0)
521     {
522         if (n > 0)
523         {
524             snprintf(num,sizeof(num),"%10d",n);
525             if (nthreads < 0)
526                 snprintf(thstr, sizeof(thstr), "N/A");
527             else
528                 snprintf(thstr, sizeof(thstr), "%4d", nthreads);
529         }
530         else
531         {
532             sprintf(num,"          ");
533             sprintf(thstr, "    ");
534         }
535         wallt = c*c2t*nnodes_tot/(double)nnodes;
536         fprintf(fplog," %-19s %4d %4s %10s  %10.3f %12.3f   %5.1f\n",
537                 name,nnodes,thstr,num,wallt,c*1e-9,100*c/tot);
538     }
539 }
540
541 static void print_gputimes(FILE *fplog, const char *name, 
542                            int n, double t, double tot_t)
543 {
544     char num[11];
545     char avg_perf[11];
546
547     if (n > 0)
548     {
549         snprintf(num, sizeof(num), "%10d", n);
550         snprintf(avg_perf, sizeof(avg_perf), "%10.3f", t/n);
551     }
552     else
553     {
554       sprintf(num,"          ");
555       sprintf(avg_perf,"          ");
556     }
557     if (t != tot_t)
558     {
559         fprintf(fplog, " %-29s %10s%12.3f   %s   %5.1f\n",
560                 name, num, t/1000, avg_perf, 100 * t/tot_t); 
561     }
562     else
563     {
564          fprintf(fplog, " %-29s %10s%12.3f   %s   %5.1f\n",
565                name, "", t/1000, avg_perf, 100.0); 
566     }
567 }
568
569 void wallcycle_print(FILE *fplog, int nnodes, int npme, double realtime,
570                      gmx_wallcycle_t wc, wallclock_gpu_t *gpu_t)
571 {
572     double *cycles;
573     double c2t,tot,tot_gpu,tot_cpu_overlap,gpu_cpu_ratio,sum,tot_k;
574     int    i,j,npp,nth_pp,nth_pme;
575     char   buf[STRLEN];
576     const char *hline = "-----------------------------------------------------------------------------";
577     
578     if (wc == NULL)
579     {
580         return;
581     }
582
583     nth_pp  = wc->nthreads_pp;
584     nth_pme = wc->nthreads_pme;
585
586     cycles = wc->cycles_sum;
587
588     if (npme > 0)
589     {
590         npp = nnodes - npme;
591     }
592     else
593     {
594         npp  = nnodes;
595         npme = nnodes;
596     }
597     tot = cycles[ewcRUN];
598
599     /* Conversion factor from cycles to seconds */
600     if (tot > 0)
601     {
602         c2t = realtime/tot;
603     }
604     else
605     {
606         c2t = 0;
607     }
608
609     fprintf(fplog,"\n     R E A L   C Y C L E   A N D   T I M E   A C C O U N T I N G\n\n");
610
611     fprintf(fplog," Computing:         Nodes   Th.     Count  Wall t (s)     G-Cycles       %c\n",'%');
612     fprintf(fplog,"%s\n",hline);
613     sum = 0;
614     for(i=ewcPPDURINGPME+1; i<ewcNR; i++)
615     {
616         if (!is_pme_subcounter(i))
617         {
618             print_cycles(fplog,c2t,wcn[i],nnodes,
619                          is_pme_counter(i) ? npme : npp,
620                          is_pme_counter(i) ? nth_pme : nth_pp, 
621                          wc->wcc[i].n,cycles[i],tot);
622             sum += cycles[i];
623         }
624     }
625     if (wc->wcc_all != NULL)
626     {
627         for(i=0; i<ewcNR; i++)
628         {
629             for(j=0; j<ewcNR; j++)
630             {
631                 snprintf(buf,9,"%-9s",wcn[i]);
632                 buf[9] = ' ';
633                 snprintf(buf+10,9,"%-9s",wcn[j]);
634                 buf[19] = '\0';
635                 print_cycles(fplog,c2t,buf,nnodes,
636                              is_pme_counter(i) ? npme : npp,
637                              is_pme_counter(i) ? nth_pme : nth_pp,
638                              wc->wcc_all[i*ewcNR+j].n,
639                              wc->wcc_all[i*ewcNR+j].c,
640                              tot);
641             }
642         }
643     }
644     print_cycles(fplog,c2t,"Rest",npp,npp,-1,0,tot-sum,tot);
645     fprintf(fplog,"%s\n",hline);
646     print_cycles(fplog,c2t,"Total",nnodes,nnodes,-1,0,tot,tot);
647     fprintf(fplog,"%s\n",hline);
648     
649     if (wc->wcc[ewcPMEMESH].n > 0)
650     {
651         fprintf(fplog,"%s\n",hline);
652         for(i=ewcPPDURINGPME+1; i<ewcNR; i++)
653         {
654             if (is_pme_subcounter(i))
655             {
656                 print_cycles(fplog,c2t,wcn[i],nnodes,
657                              is_pme_counter(i) ? npme : npp,
658                              is_pme_counter(i) ? nth_pme : nth_pp,
659                              wc->wcc[i].n,cycles[i],tot);
660             }
661         }
662         fprintf(fplog,"%s\n",hline);
663     }
664
665 #ifdef GMX_CYCLE_SUBCOUNTERS
666     fprintf(fplog,"%s\n",hline);
667     for(i=0; i<ewcsNR; i++)
668     {
669         print_cycles(fplog,c2t,wcsn[i],nnodes,npp,nth_pp,
670                      wc->wcsc[i].n,cycles[ewcNR+i],tot);
671     }
672     fprintf(fplog,"%s\n",hline);
673 #endif
674
675     /* print GPU timing summary */
676     if (gpu_t)
677     {
678         const char *k_log_str[2][2] = {
679                 {"Nonbonded F kernel", "Nonbonded F+ene k."},
680                 {"Nonbonded F+prune k.", "Nonbonded F+ene+prune k."}};
681
682         tot_gpu = gpu_t->pl_h2d_t + gpu_t->nb_h2d_t + gpu_t->nb_d2h_t;
683
684         /* add up the kernel timings */
685         tot_k = 0.0;
686         for (i = 0; i < 2; i++)
687         {
688             for(j = 0; j < 2; j++)
689             {
690                 tot_k += gpu_t->ktime[i][j].t;
691             }
692         }
693         tot_gpu += tot_k;
694     
695         tot_cpu_overlap = wc->wcc[ewcFORCE].c;
696         if (wc->wcc[ewcPMEMESH].n > 0)
697         {
698             tot_cpu_overlap += wc->wcc[ewcPMEMESH].c;
699         }
700         tot_cpu_overlap *= c2t * 1000; /* convert s to ms */
701
702         fprintf(fplog, "\n GPU timings\n%s\n", hline);
703         fprintf(fplog," Computing:                         Count  Wall t (s)      ms/step       %c\n",'%');
704         fprintf(fplog, "%s\n", hline);
705         print_gputimes(fplog, "Pair list H2D",
706                 gpu_t->pl_h2d_c, gpu_t->pl_h2d_t, tot_gpu);
707          print_gputimes(fplog, "X / q H2D", 
708                 gpu_t->nb_c, gpu_t->nb_h2d_t, tot_gpu);
709
710         for (i = 0; i < 2; i++)
711         {
712             for(j = 0; j < 2; j++)
713             {
714                 if (gpu_t->ktime[i][j].c)
715                 {
716                     print_gputimes(fplog, k_log_str[i][j],
717                             gpu_t->ktime[i][j].c, gpu_t->ktime[i][j].t, tot_gpu);
718                 }
719             }
720         }        
721
722         print_gputimes(fplog, "F D2H",  gpu_t->nb_c, gpu_t->nb_d2h_t, tot_gpu);
723         fprintf(fplog, "%s\n", hline);
724         print_gputimes(fplog, "Total ", gpu_t->nb_c, tot_gpu, tot_gpu);
725         fprintf(fplog, "%s\n", hline);
726
727         gpu_cpu_ratio = tot_gpu/tot_cpu_overlap;
728         fprintf(fplog, "\nForce evaluation time GPU/CPU: %.3f ms/%.3f ms = %.3f\n",
729                 tot_gpu/gpu_t->nb_c, tot_cpu_overlap/wc->wcc[ewcFORCE].n,
730                 gpu_cpu_ratio);
731
732         /* only print notes related to CPU-GPU load balance with PME */
733         if (wc->wcc[ewcPMEMESH].n > 0)
734         {
735             fprintf(fplog, "For optimal performance this ratio should be close to 1!\n");
736
737             /* print note if the imbalance is high with PME case in which
738              * CPU-GPU load balancing is possible */
739             if (gpu_cpu_ratio < 0.75 || gpu_cpu_ratio > 1.2)
740             {
741                 /* Only the sim master calls this function, so always print to stderr */
742                 if (gpu_cpu_ratio < 0.75)
743                 {
744                     if (npp > 1)
745                     {
746                         /* The user could have used -notunepme,
747                          * but we currently can't check that here.
748                          */
749                         md_print_warn(NULL,fplog,
750                                       "\nNOTE: The GPU has >25%% less load than the CPU. This imbalance causes\n"
751                                       "      performance loss. Maybe the domain decomposition limits the PME tuning.\n"
752                                       "      In that case, try setting the DD grid manually (-dd) or lowering -dds.");
753                     }
754                     else
755                     {
756                         /* We should not end up here, unless the box is
757                          * too small for increasing the cut-off for PME tuning.
758                          */
759                         md_print_warn(NULL,fplog,
760                                       "\nNOTE: The GPU has >25%% less load than the CPU. This imbalance causes\n"
761                                       "      performance loss.");
762                     }
763                 }
764                 if (gpu_cpu_ratio > 1.2)
765                 {
766                     md_print_warn(NULL,fplog,
767                                   "\nNOTE: The GPU has >20%% more load than the CPU. This imbalance causes\n"
768                                   "      performance loss, consider using a shorter cut-off and a finer PME grid.");
769                 }
770             }
771         }
772     }
773
774     if (wc->wcc[ewcNB_XF_BUF_OPS].n > 0 &&
775         (cycles[ewcDOMDEC] > tot*0.1 ||
776          cycles[ewcNS] > tot*0.1))
777     {
778         /* Only the sim master calls this function, so always print to stderr */
779         if (wc->wcc[ewcDOMDEC].n == 0)
780         {
781             md_print_warn(NULL,fplog,
782                           "NOTE: %d %% of the run time was spent in pair search,\n"
783                           "      you might want to increase nstlist (this has no effect on accuracy)\n",
784                           (int)(100*cycles[ewcNS]/tot+0.5));
785         }
786         else
787         {
788             md_print_warn(NULL,fplog,
789                           "NOTE: %d %% of the run time was spent in domain decomposition,\n"
790                           "      %d %% of the run time was spent in pair search,\n"
791                           "      you might want to increase nstlist (this has no effect on accuracy)\n",
792                           (int)(100*cycles[ewcDOMDEC]/tot+0.5),
793                           (int)(100*cycles[ewcNS]/tot+0.5));
794         }
795     }
796
797     if (cycles[ewcMoveE] > tot*0.05)
798     {
799         /* Only the sim master calls this function, so always print to stderr */
800         md_print_warn(NULL,fplog,
801                       "NOTE: %d %% of the run time was spent communicating energies,\n"
802                       "      you might want to use the -gcom option of mdrun\n",
803                       (int)(100*cycles[ewcMoveE]/tot+0.5));
804     }
805 }
806
807 extern gmx_large_int_t wcycle_get_reset_counters(gmx_wallcycle_t wc)
808 {
809     if (wc == NULL)
810     {
811         return -1;
812     }
813     
814     return wc->reset_counters;
815 }
816
817 extern void wcycle_set_reset_counters(gmx_wallcycle_t wc, gmx_large_int_t reset_counters)
818 {
819     if (wc == NULL)
820         return;
821
822     wc->reset_counters = reset_counters;
823 }
824
825 #ifdef GMX_CYCLE_SUBCOUNTERS
826
827 void wallcycle_sub_start(gmx_wallcycle_t wc, int ewcs)
828 {
829     if (wc != NULL)
830     {
831         wc->wcsc[ewcs].start = gmx_cycles_read();
832     }
833 }
834
835 void wallcycle_sub_stop(gmx_wallcycle_t wc, int ewcs)
836 {
837     if (wc != NULL)
838     {
839         wc->wcsc[ewcs].c += gmx_cycles_read() - wc->wcsc[ewcs].start;
840         wc->wcsc[ewcs].n++;
841     }
842 }
843
844 #endif /* GMX_CYCLE_SUBCOUNTERS */