improve process tracing, update examples and test names

CMakeLists.txt

@@ -70,25 +70,25 @@ target_link_libraries(${PROJECT_NAME}proc dl)
 install(TARGETS ${PROJECT_NAME}proc DESTINATION lib)
 
 # Example - ex001 - regular program / non-instrumented
-add_executable(ex001 tests/ex.c)
+add_executable(ex001 tests/ex001.c)
 target_link_libraries(ex001 pthread)
 
 # Example - ex002 - instrumented
-add_executable(ex002 tests/ex.c)
+add_executable(ex002 tests/ex002.c)
 set_target_properties(ex002 PROPERTIES COMPILE_FLAGS "-rdynamic -finstrument-functions")
 target_link_libraries(ex002 pthread cpuusage)
 
 # Example - ex003 - manually instrumented
-add_executable(ex003 tests/ex3.cpp src/cpuusage.h)
+add_executable(ex003 tests/ex003.cpp src/cpuusage.h)
 target_link_libraries(ex003 pthread cpuusage)
 
 # Example - ex004 - simple program (sleep)
-add_executable(ex004 tests/ex4.cpp)
+add_executable(ex004 tests/ex004.cpp)
 target_link_libraries(ex004)
 
 # Example - ex005 - simple scripts
-configure_file(tests/ex5.sh ${CMAKE_CURRENT_BINARY_DIR}/ex005.sh COPYONLY)
-configure_file(tests/ex5b.sh ${CMAKE_CURRENT_BINARY_DIR}/ex005b.sh COPYONLY)
+configure_file(tests/ex005.sh ${CMAKE_CURRENT_BINARY_DIR}/ex005.sh COPYONLY)
+configure_file(tests/ex005b.sh ${CMAKE_CURRENT_BINARY_DIR}/ex005b.sh COPYONLY)
 
 # Tests
 enable_testing()

src/cpuusage

@@ -52,30 +52,33 @@ showusage()
   echo "   [ARGS]          optional arguments to the program"
   echo ""
   echo "Examples:"
-  echo "cpuusage -o cutrace.html -a ./build/cutest1"
-  echo "                   trace all standard POSIX function calls in ./build/cutest1"
-  echo "                   and write log to cutrace.html"
-  echo ""
-  echo "cpuusage -o cutrace.html -c ./build/cutest2"
-  echo "                   trace instrumented functions in ./build/cutest2 and write"
+  echo "cpuusage -o cutrace.html -a ./build/ex001"
+  echo "                   trace all standard POSIX function calls and write"
   echo "                   log to cutrace.html"
   echo ""
-  echo "cpuusage -o cutrace.html -f fopen,fclose,fread,fwrite ./build/cutest1"
+  echo "cpuusage -o cutrace.html -c ./build/ex002"
+  echo "                   trace instrumented functions and write log to"
+  echo "                   cutrace.html"
+  echo ""
+  echo "cpuusage -o cutrace.html -f fopen,fclose,fread,fwrite ./build/ex001"
   echo "                   trace calls to fopen, fclose, fread and fwrite, and write"
   echo "                   log to cutrace.html"
   echo ""
-  echo "cpuusage -o cutrace.html -i stdio.h ./build/cutest1"
+  echo "cpuusage -o cutrace.html -i stdio.h ./build/ex001"
   echo "                   trace calls to all POSIX functions in stdio.h and write"
   echo "                   log to cutrace.html"
   echo ""
+  echo "cpuusage -o cutrace.html -p ./build/ex005.sh"
+  echo "                   trace process durations and write to cutrace.html"
+  echo ""
   echo "Report bugs at https://github.com/d99kris/cpuusage"
   echo ""
 }
 
 # Version
 showversion()
 {
-  echo "cpuusage v1.43"
+  echo "cpuusage v1.46"
   echo ""
   echo "Copyright (C) 2017-2021 Kristofer Berggren"
   echo ""

src/cpuusage.1

@@ -1,5 +1,5 @@
 .\" DO NOT MODIFY THIS FILE!  It was generated by help2man.
-.TH CPUUSAGE "1" "February 2021" "cpuusage v1.43" "User Commands"
+.TH CPUUSAGE "1" "December 2021" "cpuusage v1.46" "User Commands"
 .SH NAME
 cpuusage \- instrumentation CPU profiler
 .SH SYNOPSIS
@@ -98,25 +98,29 @@ program to run and profile
 [ARGS]
 optional arguments to the program
 .SH EXAMPLES
-cpuusage \-o cutrace.html \-a ./build/cutest1
+cpuusage \-o cutrace.html \-a ./build/ex001
 .IP
-trace all standard POSIX function calls in ./build/cutest1
-and write log to cutrace.html
+trace all standard POSIX function calls and write
+log to cutrace.html
 .PP
-cpuusage \-o cutrace.html \-c ./build/cutest2
+cpuusage \-o cutrace.html \-c ./build/ex002
 .IP
-trace instrumented functions in ./build/cutest2 and write
-log to cutrace.html
+trace instrumented functions and write log to
+cutrace.html
 .PP
-cpuusage \-o cutrace.html \-f fopen,fclose,fread,fwrite ./build/cutest1
+cpuusage \-o cutrace.html \-f fopen,fclose,fread,fwrite ./build/ex001
 .IP
 trace calls to fopen, fclose, fread and fwrite, and write
 log to cutrace.html
 .PP
-cpuusage \-o cutrace.html \-i stdio.h ./build/cutest1
+cpuusage \-o cutrace.html \-i stdio.h ./build/ex001
 .IP
 trace calls to all POSIX functions in stdio.h and write
 log to cutrace.html
+.PP
+cpuusage \-o cutrace.html \-p ./build/ex005.sh
+.IP
+trace process durations and write to cutrace.html
 .SH AUTHOR
 Written by Kristofer Berggren
 .SH "REPORTING BUGS"

src/cupmain.cpp

@@ -244,35 +244,31 @@ static void cup_handleevent(bool p_IsStart)
 {
   if (getenv("LD_PRELOAD") == NULL) return;
 
-  // @todo: figure out why isFirstProcess static is not retained for final call
-  static bool isFirstProcess = false;
   static char default_path[32];
   static char* path = NULL;
   static int64_t beginTime = 0;
 
-  if (p_IsStart)
+  // determine report path
+  path = getenv("CU_FILE");
+  if (path == NULL)
   {
-    // determine report path
-    path = getenv("CU_FILE");
-    if (path == NULL)
-    {
-      snprintf(default_path, sizeof(default_path), "./culog-%d.json", getpid());
-      path = default_path;
-    }
+    snprintf(default_path, sizeof(default_path), "./culog-%d.json", getpid());
+    path = default_path;
+  }
 
+  if (p_IsStart)
+  {
     // check if file does not exist
     if (access(path, F_OK) == -1)
     {
       // remember this is the main process
-      isFirstProcess = true;
+      std::string pid = std::to_string(getpid());
+      setenv("CU_FIRST_PROCESS", pid.c_str(), true);
 
       // write header
       cup_writeheader(path);
     }
 
-    // store first process flag in environment
-    setenv("CU_IS_FIRST_PROCESS", isFirstProcess ? "1" : "0", true);
-
     // store begin timestamp
     struct timeval tv;
     gettimeofday(&tv, NULL);
@@ -285,9 +281,10 @@ static void cup_handleevent(bool p_IsStart)
     gettimeofday(&tv, NULL);
     const int64_t endTime = ((int64_t)tv.tv_sec * 1000000ll) + ((int64_t)tv.tv_usec);
 
-    // read back first process flag from environment
-    char* isFirstStr = getenv("CU_IS_FIRST_PROCESS");
-    isFirstProcess = (isFirstStr != NULL) && (strncmp(isFirstStr, "1", 1) == 0);
+    // read back first process id from environment
+    std::string firstpid = std::string(getenv("CU_FIRST_PROCESS"));
+    std::string pid = std::to_string(getpid());
+    const bool isFirstProcess = (pid == firstpid);
 
     char* isExpandStr = getenv("CU_EXPAND_PROCESSES");
     bool isExpandProcesses = (isExpandStr != NULL) && (strncmp(isExpandStr, "1", 1) == 0);

tests/ex.c → tests/ex001.c

@@ -1,5 +1,5 @@
 /*
- * ex.c
+ * ex001.c
  *
  * Copyright (C) 2017 Kristofer Berggren
  * All rights reserved.

tests/ex002.c

@@ -0,0 +1,73 @@
+/*
+ * ex002.c
+ *
+ * Copyright (C) 2017 Kristofer Berggren
+ * All rights reserved.
+ * 
+ * cpuusage is distributed under the BSD 3-Clause license, see LICENSE for details.
+ *
+ */
+
+/* ----------- Includes ------------------------------------------ */
+#include <fcntl.h>
+#include <limits.h>
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <unistd.h>
+
+
+/* ----------- Function Prototypes ------------------------------- */
+void copy_large_file();
+void copy_medium_file();
+void copy_small_file();
+
+
+/* ----------- Global Functions ---------------------------------- */
+int main(void)
+{
+  copy_large_file();
+  copy_medium_file();
+  copy_small_file();
+  return 0;
+}
+
+void copy_large_file()
+{
+  int large_size = 1024 * 1024 * 1024;
+  char *buf = calloc(1, large_size);
+  FILE* fin = fopen("/dev/null", "r");
+  FILE* fout = fopen("/dev/null", "w");
+  fread(buf, large_size, 1, fin);
+  fclose(fin);
+  fwrite(buf, large_size, 1, fout);
+  fclose(fout);
+  free(buf);
+}
+
+void copy_medium_file()
+{
+  int medium_size = 128 * 1024 * 1024;
+  char *buf = calloc(1, medium_size);
+  FILE* fin = fopen("/dev/null", "r");
+  FILE* fout = fopen("/dev/null", "w");
+  fread(buf, medium_size, 1, fin);
+  fclose(fin);
+  fwrite(buf, medium_size, 1, fout);
+  fclose(fout);
+  free(buf);
+}
+
+void copy_small_file()
+{
+  int small_size = 1024 * 1024;
+  char *buf = calloc(1, small_size);
+  FILE* fin = fopen("/dev/null", "r");
+  FILE* fout = fopen("/dev/null", "w");
+  fread(buf, small_size, 1, fin);
+  fclose(fin);
+  fwrite(buf, small_size, 1, fout);
+  fclose(fout);
+  free(buf);
+}
+

tests/ex3.cpp → tests/ex003.cpp

@@ -1,5 +1,5 @@
 /*
- * ex3.cpp
+ * ex003.cpp
  *
  * Copyright (C) 2018 Kristofer Berggren
  * All rights reserved.

tests/ex4.cpp → tests/ex004.cpp

@@ -1,5 +1,5 @@
 /*
- * ex4.cpp
+ * ex004.cpp
  *
  * Copyright (C) 2020 Kristofer Berggren
  * All rights reserved.

tests/ex005.sh

@@ -0,0 +1,8 @@
+#!/usr/bin/env bash
+
+# ex005.sh
+
+sleep 1
+SCRIPTPATH="$(cd -- "$(dirname "$0")" >/dev/null 2>&1; pwd -P)"
+${SCRIPTPATH}/ex005b.sh
+sleep 2

tests/ex5b.sh → tests/ex005b.sh

@@ -1,3 +1,5 @@
 #!/usr/bin/env bash
 
+# ex005b.sh
+
 sleep 1

tests/test005

@@ -52,7 +52,7 @@ if [ "${LINE}" != "${EXPT}" ]; then
 fi
 
 LINE=$(cat ${TMPDIR}/out.txt | head -5 | tail -1)
-EXPT="cpuusage: completed processing 5 samples"
+EXPT="cpuusage: completed processing 7 samples"
 if [ "${LINE}" != "${EXPT}" ]; then
   echo "Output mismatch: \"${LINE}\" != \"${EXPT}\""
   echo "Full test output:"