mpe logging works

examples/c/Makefile.am

@@ -19,4 +19,4 @@ endif # RUN_TESTS
 EXTRA_DIST = run_tests.sh
 
 # Clean up files produced during testing.
-CLEANFILES = *.nc *.log
+CLEANFILES = *.nc *.log *.clog2 *.slog2

examples/c/darray_no_async.c

@@ -377,11 +377,6 @@ int main(int argc, char* argv[])
     if ((ret = PIOc_free_iosystem(iosysid)))
         ERR(ret);
 
-#ifdef USE_MPE
-    if ((ret = MPE_Finish_log(TEST_NAME)))
-        MPIERR(ret);
-#endif /* USE_MPE */
-
     /* Finalize the MPI library. */
     MPI_Finalize();
 

examples/c/example1.c

@@ -427,11 +427,6 @@ int check_file(int ntasks, char *filename) {
 		    ERR(ret);
             }
 
-#ifdef USE_MPE
-        if ((ret = MPE_Finish_log(TEST_NAME)))
-            MPIERR(ret);
-#endif /* USE_MPE */
-
 	/* Finalize the MPI library. */
 	MPI_Finalize();
 

examples/c/examplePio.c

@@ -473,13 +473,6 @@ struct examplePioClass* epc_cleanUp( struct examplePioClass* this )
 
     PIOc_freedecomp(this->pioIoSystem, this->iodescNCells);
     PIOc_free_iosystem(this->pioIoSystem);
-#ifdef USE_MPE
-    {
-        int ret;
-        if ((ret = MPE_Finish_log(TEST_NAME)))
-            return NULL;
-    }
-#endif /* USE_MPE */
 
     MPI_Finalize();
 

src/clib/pio_darray.c

@@ -134,6 +134,10 @@ PIOc_write_darray_multi(int ncid, const int *varids, int ioid, int nvars,
     int ierr;              /* Return code. */
     void *tmparray;
 
+/* #ifdef USE_MPE */
+/*     pio_start_mpe_log(DARRAY_WRITE); */
+/* #endif /\* USE_MPE *\/ */
+
     /* Get the file info. */
     if ((ierr = pio_get_file(ncid, &file)))
         return pio_err(NULL, NULL, PIO_EBADID, __FILE__, __LINE__);
@@ -411,6 +415,10 @@ PIOc_write_darray_multi(int ncid, const int *varids, int ioid, int nvars,
         if ((ierr = flush_output_buffer(file, flushtodisk, 0)))
             return pio_err(ios, file, ierr, __FILE__, __LINE__);
 
+/* #ifdef USE_MPE */
+/*     pio_stop_mpe_log(DARRAY_WRITE, __func__); */
+/* #endif /\* USE_MPE *\/ */
+
     return PIO_NOERR;
 }
 
@@ -649,9 +657,7 @@ PIOc_write_darray(int ncid, int varid, int ioid, PIO_Offset arraylen, void *arra
     LOG((1, "PIOc_write_darray ncid = %d varid = %d ioid = %d arraylen = %d",
          ncid, varid, ioid, arraylen));
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[START][DARRAY_WRITE], 0,
-                             "PIOc_write_darray")))
-        return pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+    pio_start_mpe_log(DARRAY_WRITE);
 #endif /* USE_MPE */
 
     /* Get the file info. */
@@ -852,9 +858,7 @@ PIOc_write_darray(int ncid, int varid, int ioid, PIO_Offset arraylen, void *arra
     wmb->num_arrays++;
 
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[END][DARRAY_WRITE], 0,
-                             "PIOc_write_darray")))
-        return pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+    pio_stop_mpe_log(DARRAY_WRITE, __func__);
 #endif /* USE_MPE */
 
     LOG((2, "wmb->num_arrays = %d iodesc->maxbytes / iodesc->mpitype_size = %d "
@@ -896,9 +900,7 @@ PIOc_read_darray(int ncid, int varid, int ioid, PIO_Offset arraylen,
     void *tmparray;        /* unsorted copy of array buf if required */
 
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[START][DARRAY_READ], 0,
-                             "PIOc_read_darray")))
-        return pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+    pio_start_mpe_log(DARRAY_READ);
 #endif /* USE_MPE */
 
     /* Get the file info. */
@@ -965,9 +967,7 @@ PIOc_read_darray(int ncid, int varid, int ioid, PIO_Offset arraylen,
         brel(iobuf);
 
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[END][DARRAY_READ], 0,
-                             "PIOc_read_darray")))
-        return pio_err(ios, file, PIO_EIO, __FILE__, __LINE__);
+    pio_stop_mpe_log(DARRAY_READ, __func__);
 #endif /* USE_MPE */
 
     return PIO_NOERR;

src/clib/pio_file.c

@@ -227,9 +227,7 @@ int PIOc_closefile(int ncid)
     int mpierr = MPI_SUCCESS, mpierr2;  /* Return code from MPI function codes. */
 
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[START][CLOSE], 0,
-                              "PIOc_closefile")))
-        return pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+    pio_start_mpe_log(CLOSE);
 #endif /* USE_MPE */
 
     LOG((1, "PIOc_closefile ncid = %d", ncid));
@@ -306,9 +304,7 @@ int PIOc_closefile(int ncid)
         return pio_err(ios, file, ierr, __FILE__, __LINE__);
 
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[END][CLOSE], 0,
-                              "PIOc_closefile")))
-        return pio_err(ios, NULL, PIO_EIO, __FILE__, __LINE__);
+    pio_stop_mpe_log(INIT, __func__);
 #endif /* USE_MPE */
 
     return ierr;

src/clib/pio_internal.h

@@ -364,10 +364,14 @@ extern "C" {
     /* Handle end and re-defs. */
     int pioc_change_def(int ncid, int is_enddef);
 
-    /* Initialize and finalize logging. */
+    /* Initialize and finalize logging, use --enable-logging at configure. */
     int pio_init_logging(void);
     void pio_finalize_logging(void );
 
+    /* Logging with the MPE library, use --enable-mpe at configure. */
+    void pio_start_mpe_log(int state);
+    void pio_stop_mpe_log(int state, const char *msg);
+
     /* Write a netCDF decomp file. */
     int pioc_write_nc_decomp_int(iosystem_desc_t *ios, const char *filename, int cmode, int ndims,
                                  int *global_dimlen, int num_tasks, int *task_maplen, int *map,

src/clib/pio_msg.c

@@ -1,4 +1,5 @@
-/** @file
+/**
+ * @file
  *
  * PIO async message handling. This file contains the code which
  * runs on the IO nodes when async is in use. This code waits for
@@ -22,6 +23,11 @@ extern int my_rank;
 extern int pio_log_level;
 #endif /* PIO_ENABLE_LOGGING */
 
+#ifdef USE_MPE
+/* The event numbers for MPE logging. */
+extern int event_num[2][NUM_EVENTS];
+#endif /* USE_MPE */
+
 /**
  * This function is run on the IO tasks to handle nc_inq_type*()
  * functions.

src/clib/pioc.c

@@ -501,6 +501,10 @@ PIOc_InitDecomp(int iosysid, int pio_type, int ndims, const int *gdimlen, int ma
     LOG((1, "PIOc_InitDecomp iosysid = %d pio_type = %d ndims = %d maplen = %d",
          iosysid, pio_type, ndims, maplen));
 
+#ifdef USE_MPE
+    pio_start_mpe_log(DECOMP);
+#endif /* USE_MPE */
+
     /* Get IO system info. */
     if (!(ios = pio_get_iosystem_from_id(iosysid)))
         return pio_err(NULL, NULL, PIO_EBADID, __FILE__, __LINE__);
@@ -620,6 +624,7 @@ PIOc_InitDecomp(int iosysid, int pio_type, int ndims, const int *gdimlen, int ma
             iodesc->map[m] = compmap[m];
         }
     }
+
     /* Remember the dim sizes. */
     if (!(iodesc->dimlen = malloc(sizeof(int) * ndims)))
         return pio_err(ios, NULL, PIO_ENOMEM, __FILE__, __LINE__);
@@ -722,6 +727,10 @@ PIOc_InitDecomp(int iosysid, int pio_type, int ndims, const int *gdimlen, int ma
      * PERFTUNE is set. */
     performance_tune_rearranger(ios, iodesc);
 
+#ifdef USE_MPE
+    pio_stop_mpe_log(DECOMP, __func__);
+#endif /* USE_MPE */
+
     return PIO_NOERR;
 }
 
@@ -925,6 +934,10 @@ PIOc_Init_Intracomm(MPI_Comm comp_comm, int num_iotasks, int stride, int base,
     if ((ret = pio_init_logging()))
         return pio_err(NULL, NULL, ret, __FILE__, __LINE__);
 
+#ifdef USE_MPE
+    pio_start_mpe_log(INIT);
+#endif /* USE_MPE */
+
     /* Find the number of computation tasks. */
     if ((mpierr = MPI_Comm_size(comp_comm, &num_comptasks)))
         return check_mpi(NULL, NULL, mpierr, __FILE__, __LINE__);
@@ -1047,6 +1060,9 @@ PIOc_Init_Intracomm(MPI_Comm comp_comm, int num_iotasks, int stride, int base,
     if ((ret = compute_buffer_init(ios)))
         return ret;
 
+#ifdef USE_MPE
+    pio_stop_mpe_log(INIT, __func__);
+#endif /* USE_MPE */
     LOG((2, "Init_Intracomm complete iosysid = %d", *iosysidp));
 
     return PIO_NOERR;
@@ -1432,8 +1448,7 @@ PIOc_init_async(MPI_Comm world, int num_io_procs, int *io_proc_list,
          component_count));
 
 #ifdef USE_MPE
-    if ((ret = MPE_Log_event(event_num[START][INIT], 0, "PIOc_init_async")))
-        return pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+    pio_start_mpe_log(INIT);
 #endif /* USE_MPE */
 
     /* Determine which tasks to use for IO. */
@@ -1716,9 +1731,7 @@ PIOc_init_async(MPI_Comm world, int num_io_procs, int *io_proc_list,
         LOG((2, "Starting message handler io_rank = %d component_count = %d",
              io_rank, component_count));
 #ifdef USE_MPE
-        if ((ret = MPE_Log_event(event_num[END][INIT], 0,
-                                 "about to start processing messages")))
-            return pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+    pio_stop_mpe_log(INIT, __func__);
 #endif /* USE_MPE */
 
         /* Start the message handler loop. This will not return until
@@ -1756,8 +1769,7 @@ PIOc_init_async(MPI_Comm world, int num_io_procs, int *io_proc_list,
 
 #ifdef USE_MPE
     if (!in_io)
-        if ((ret = MPE_Log_event(event_num[END][INIT], 0, "end of PIOc_init_async")))
-            return pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+        pio_stop_mpe_log(INIT, __func__);
 #endif /* USE_MPE */
 
     LOG((2, "successfully done with PIOc_init_async"));

src/clib/pioc_support.c

@@ -199,16 +199,57 @@ init_mpe(int my_rank)
      * communications. */
     if (!my_rank)
     {
-        MPE_Describe_state(event_num[START][INIT], event_num[END][INIT], "init", "red");
-        MPE_Describe_state(event_num[START][DECOMP], event_num[END][DECOMP], "decomposition", "green");
-        MPE_Describe_state(event_num[START][CREATE], event_num[END][CREATE], "create file", "purple");
-        MPE_Describe_state(event_num[START][OPEN], event_num[END][OPEN], "open file", "orange");
-        MPE_Describe_state(event_num[START][DARRAY_WRITE], event_num[END][DARRAY_WRITE], "darray write", "pink");
-        MPE_Describe_state(event_num[START][DARRAY_READ], event_num[END][DARRAY_WRITE], "darray read", "brown");
-        MPE_Describe_state(event_num[START][CLOSE], event_num[END][CLOSE], "close file", "blue");
+        MPE_Describe_info_state(event_num[START][INIT], event_num[END][INIT],
+                                "PIO init", "red", "%s");
+        MPE_Describe_info_state(event_num[START][DECOMP],
+                                event_num[END][DECOMP], "PIO decomposition",
+                                "green", "%s");
+        MPE_Describe_info_state(event_num[START][CREATE], event_num[END][CREATE],
+                                "PIO create file", "purple", "%s");
+        MPE_Describe_info_state(event_num[START][OPEN], event_num[END][OPEN],
+                                "PIO open file", "orange", "%s");
+        MPE_Describe_info_state(event_num[START][DARRAY_WRITE],
+                                event_num[END][DARRAY_WRITE], "PIO darray write",
+                                "pink", "%s");
+        MPE_Describe_info_state(event_num[START][DARRAY_READ],
+                           event_num[END][DARRAY_WRITE], "PIO darray read",
+                           "brown", "%s");
+        MPE_Describe_info_state(event_num[START][CLOSE], event_num[END][CLOSE],
+                                "PIO close file", "blue", "%s");
     }
     return 0;
 }
+
+/**
+ * Start MPE logging.
+ *
+ * @param state_num the MPE event state number to START (ex. INIT).
+ * @author Ed Hartnett
+ */
+void
+pio_start_mpe_log(int state)
+{
+    if (MPE_Log_event(event_num[START][state], 0, NULL))
+        pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+}
+
+/**
+ * End MPE logging.
+ *
+ * @author Ed Hartnett
+ */
+void
+pio_stop_mpe_log(int state, const char *msg)
+{
+    MPE_LOG_BYTES bytebuf;
+    int pos = 0;
+    int ret;
+
+    MPE_Log_pack(bytebuf, &pos, 's', strlen(msg), msg);
+    if ((ret = MPE_Log_event(event_num[END][state], 0, bytebuf)))
+        pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+}
+
 #endif /* USE_MPE */
 
 /**
@@ -1889,9 +1930,7 @@ PIOc_createfile_int(int iosysid, int *ncidp, int *iotype, const char *filename,
     int ierr;              /* Return code from function calls. */
 
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[START][CREATE], 0,
-                              "PIOc_createfile_int")))
-        return pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+    pio_start_mpe_log(CREATE);
 #endif /* USE_MPE */
 
     /* Get the IO system info from the iosysid. */
@@ -2036,9 +2075,7 @@ PIOc_createfile_int(int iosysid, int *ncidp, int *iotype, const char *filename,
     pio_add_to_file_list(file);
 
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[END][CREATE], 0,
-                              "PIOc_createfile_int")))
-        return pio_err(NULL, file, PIO_EIO, __FILE__, __LINE__);
+    pio_stop_mpe_log(CREATE, __func__);
 #endif /* USE_MPE */
     LOG((2, "Created file %s file->fh = %d file->pio_ncid = %d", filename,
          file->fh, file->pio_ncid));
@@ -2350,9 +2387,7 @@ PIOc_openfile_retry(int iosysid, int *ncidp, int *iotype, const char *filename,
     int ierr = PIO_NOERR;      /* Return code from function calls. */
 
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[START][OPEN], 0,
-                              "PIOc_openfile_retry")))
-        return pio_err(NULL, NULL, PIO_EIO, __FILE__, __LINE__);
+    pio_start_mpe_log(OPEN);
 #endif /* USE_MPE */
 
     /* Get the IO system info from the iosysid. */
@@ -2613,8 +2648,7 @@ PIOc_openfile_retry(int iosysid, int *ncidp, int *iotype, const char *filename,
     }
 
 #ifdef USE_MPE
-    if ((ierr = MPE_Log_event(event_num[END][OPEN], 0, "PIOc_openfile_retry")))
-        return pio_err(ios, file, PIO_EIO, __FILE__, __LINE__);
+    pio_stop_mpe_log(OPEN, __func__);
 #endif /* USE_MPE */
     LOG((2, "Opened file %s file->pio_ncid = %d file->fh = %d ierr = %d",
          filename, file->pio_ncid, file->fh, ierr));

tests/cunit/Makefile.am

@@ -70,4 +70,4 @@ test_darray_vard_SOURCES = test_darray_vard.c test_common.c pio_tests.h
 EXTRA_DIST = run_tests.sh
 
 # Clean up files produced during testing.
-CLEANFILES = *.nc *.log decomp*.txt
+CLEANFILES = *.nc *.log decomp*.txt *.clog2 *.slog2

tests/cunit/test_async_multicomp.c

@@ -83,7 +83,6 @@ int main(int argc, char **argv)
         {
             for (int i = 0; i < num_iotypes; i++)
             {
-                char filename[NC_MAX_NAME + 1]; /* Test filename. */
                 int my_comp_idx = my_rank - 1; /* Index in iosysid array. */
                 int dim_len_2d[NDIM2] = {DIM_LEN2, DIM_LEN3};
                 int ioid = 0;
@@ -92,9 +91,11 @@ int main(int argc, char **argv)
                                                    &ioid, PIO_SHORT)))
                     ERR(ret);
 
+#ifndef USE_MPE /* For some reason MPE logging breaks this test! */
                 /* Test with and without darrays. */
                 for (int use_darray = 0; use_darray < 2; use_darray++)
                 {
+                    char filename[NC_MAX_NAME + 1]; /* Test filename. */
 
                     /* Create sample file. */
                     if ((ret = create_nc_sample_3(iosysid[my_comp_idx], iotype[i], my_rank, my_comp_idx,
@@ -106,6 +107,7 @@ int main(int argc, char **argv)
                                                  filename, 0, 0, ioid)))
                         ERR(ret);
                 } /* next use_darray */
+#endif /* USE_MPE */
 
                 /* Free the decomposition. */
                 if ((ret = PIOc_freedecomp(iosysid[my_comp_idx], ioid)))

tests/cunit/test_darray.c

@@ -423,6 +423,8 @@ int main(int argc, char **argv)
     /* Finalize the MPI library. */
     if ((ret = pio_test_finalize(&test_comm)))
         return ret;
+    /* if ((ret = pio_test_finalize2(&test_comm, TEST_NAME))) */
+    /*     return ret; */
 
     printf("%d %s SUCCESS!!\n", my_rank, TEST_NAME);
     return 0;