title: Why is this call to a dynamic library function so slow?
body: <p>I am writing a shared library for python to call. Since this is my first time using python's <code>ctypes</code> module, and nearly my first time writing a shared library, I have been writing both C and python code to call the library's functions.</p>
  
  <p>For the heck of it I put some timing code in and found that, while most calls of the C program to the library are very fast, the first is slow, considerably slower than its python counterpart in fact. This goes against everything I expected and was hoping that someone could tell me why.</p>
  
  <p>Here is a stripped down version of the header file from my C library.</p>
  
  <pre><code>typedef struct MdaDataStruct
  {
      int numPts;
      int numDists;
      float* data;
      float* dists;
  } MdaData;
  
  //allocate the structure
  void* makeMdaStruct(int numPts, int numDist);
  
  //deallocate the structure
  void freeMdaStruct(void* strPtr);
  
  //assign the data array
  void setData(void* strPtr, float* divData);
  </code></pre>
  
  <p>Here is the C program that calls the functions:</p>
  
  <pre><code>int main(int argc, char* argv[])
  {
      clock_t t1, t2;
      t1=clock();
      long long int diff;
      //test the allocate function
      t1 = clock();
      MdaData* dataPtr = makeMdaStruct(10, 3);
      t2 = clock();
      diff = (((t2-t1)*1000000)/CLOCKS_PER_SEC);
      printf("make struct, took: %d microseconds\n", diff);
  
      //make some data
      float testArr[10] = {0.0, 0.1, 0.2, 0.3, 0.4, 0.5, 0.6, 0.7, 0.8, 0.9};
  
      //test the set data function
      t1 = clock();
      setData(dataPtr, testArr);
      t2 = clock();
      diff = (((t2-t1)*1000000)/CLOCKS_PER_SEC);
      printf("set data, took: %d microseconds\n", diff);
  
      //test the deallocate function
      t1 = clock();
      freeMdaStruct(dataPtr);
      t2 = clock();
      diff = (((t2-t1)*1000000)/CLOCKS_PER_SEC);
      printf("free struct, took: %d microseconds\n", diff);
  
      //exit
      return 0;
  }
  </code></pre>
  
  <p>and here is the python script that calls the functions:</p>
  
  <pre><code># load the library
  t1 = time.time()
  cs_lib = cdll.LoadLibrary("./libChiSq.so")
  t2 = time.time()
  print "load library, took", int((t2-t1)*1000000), "microseconds"
  # tell python the function will return a void pointer
  cs_lib.makeMdaStruct.restype = c_void_p
  # make the strcuture to hold the MdaData with 50 data points and 8 L dists
  t1 = time.time()
  mdaData = cs_lib.makeMdaStruct(10,3)
  t2 = time.time()
  print "make struct, took", int((t2-t1)*1000000), "microseconds"
  # make an array with the test data
  divDat = np.array([0.0, 0.1, 0.2, 0.3, 0.4, 0.5, 0.6, 0.7, 0.8, 0.9], np.float32)
  #run the function to load the array into the struct
  t1 = time.time()
  cs_lib.setData(mdaData, divDat.ctypes.data)
  t2 = time.time()
  print "set data, took", int((t2-t1)*1000000), "microseconds"
  #free the structure
  t1 = time.time()
  cs_lib.freeMdaStruct(mdaData)
  t2 = time.time()
  print "free struct, took", int((t2-t1)*1000000), "microseconds"
  </code></pre>
  
  <p>and finally, here is the output of running the two consecutively:</p>
  
  <pre><code>[]$ ./tester
  make struct, took: 60 microseconds
  set data, took: 2 microseconds
  free struct, took: 2 microseconds
  []$ python so_py_tester.py 
  load library, took 77 microseconds
  make struct, took 3 microseconds
  set data, took 23 microseconds
  free struct, took 10 microseconds
  </code></pre>
  
  <p>As you can see, the C call to makeMdaStruct takes 60us and the python call to makeMdaStruct takes 3us, which is highly confusing.</p>
  
  <p>My best guess was that somehow the C code pays the cost of loading the library at the first call? Which confuses me because I thought that the library was loaded when the program was loaded into memory.</p>
  
  <p><strong>Edit:</strong> I think there might be a kernel of truth to the guess because I put an extra untimed call to makeMdaStruct and freeMdaStruct before the timed call to makeMdaStruct and got the following output in testing:</p>
  
  <pre><code>[]$ ./tester
  make struct, took: 1 microseconds
  set data, took: 1 microseconds
  free struct, took: 0 microseconds
  []$ python so_py_tester.py 
  load library, took 70 microseconds
  make struct, took 4 microseconds
  set data, took 23 microseconds
  free struct, took 12 microseconds
  </code></pre>