c++ - difference between runtime timing function and command line time

Question

I have the following code with the timing function from https://stackoverflow.com/a/1861493/4587344 and the libbsc from https://github.com/IlyaGrebnov/libbsc.

#include <vector>
#include <iostream>

#include <random>
#include <cassert>

#include <sys/time.h> 

#include "libbsc/libbsc/libbsc.h"

typedef unsigned long long timestamp_t;

static timestamp_t
get_timestamp ()
{
  struct timeval now;
  gettimeofday (&now, NULL);
  return  now.tv_usec + (timestamp_t)now.tv_sec * 1000000;
}

int main() {

  int min = 0;
  int max = 1800;
  std::vector<int> rand_vector;

  int  bsc_length;
  int bsc_status;
  double secs_bsc;
  unsigned char* bsc_out_buffer;

  // generate random values
  for (int i=1; i<262144; ++i) rand_vector.push_back(min + (rand() % (int)(max - min + 1))); // 262144 random_integers

  char* rand_buffer = reinterpret_cast<char*> (&rand_vector[0]);
  int rand_length = sizeof (int)*rand_vector.size();

  bsc_out_buffer = (unsigned char*) malloc (rand_length + LIBBSC_HEADER_SIZE);
  const unsigned char* bsc_in_buffer = reinterpret_cast<const unsigned char*> (rand_buffer);

  bsc_status = bsc_init(LIBBSC_FEATURE_FASTMODE);

  if (bsc_status == LIBBSC_NO_ERROR){



    timestamp_t t0_bsc = get_timestamp();
    bsc_length = bsc_compress(bsc_in_buffer, // inbuffer
                  bsc_out_buffer, // outbuffer
                  rand_length, // length of inbuffer
                  LIBBSC_DEFAULT_LZPHASHSIZE,  // int lzpHashSize, 
                  LIBBSC_DEFAULT_LZPMINLEN, //int lzpMinLen, 
                  LIBBSC_DEFAULT_BLOCKSORTER, //int blockSorter, 
                  LIBBSC_CODER_QLFC_ADAPTIVE, //int coder, 
                  LIBBSC_FEATURE_FASTMODE //int features
                );
    timestamp_t t1_bsc = get_timestamp();

    secs_bsc = (t0_bsc - t1_bsc) / 1000000.0L;

  }
  else std::cout << "ERROR in bsc_init: " << bsc_status << std::endl;


  std::cout << std::fixed << "bsc_compress runtime: " << secs_bsc << std::endl;
  std::cout << "bsc_compress size: " << bsc_length << std::endl;

  unsigned char* bsc_assert_buffer;
  bsc_assert_buffer = (unsigned char*) malloc (rand_length);

  bsc_status = bsc_decompress(bsc_out_buffer, bsc_length, bsc_assert_buffer, rand_length, LIBBSC_FEATURE_FASTMODE);
  int* uncompress_values = (int*)bsc_assert_buffer;

  for(int i = 0; i < rand_vector.size(); ++i) {
      assert(uncompress_values[i] == rand_vector[i]);
  }


}

compiling it with g++ --std=c++11 test_bsc.cpp libbsc/libbsc.a -o bsc_test and executing it with time ./bsc_test

the output is

 bsc_compress runtime: 18446744073709.355469
 bsc_compress size: 357178

 real    0m0.392s
 user    0m0.384s
 sys     0m0.008s

Can anybody explain to me the difference? Is the resolution of the timing function not good enough? If I use a zlib compression I get something like 1.24294 as runtime with the same timing function and vector size.

with regards tiom

Answer 1

bsc_compress runtime: 18446744073709.355469

There are a couple of magic numbers you'll want to memorize when you are a programmer. Powers of 2 on the top of the list, memorize 15, 16, 31, 32, 63, 64 first. The latter is a match. Which helps you find the bug, you got a negative result interpreted as an unsigned 64-bit value. Fix:

secs_bsc = (t1_bsc - t0_bsc) / 1000000.0L;

Fwiw: you can't compare the two results that well, the OS measurement includes the time needed to load the executable and startup the CRT.