unexpected slowdown and cancellation point

[Mathis Ahrens <mathis dot ahrens at gmx dot de>]

Hi,

I am trying to debug a multithreaded program with gdb but get unexpected 
side effects.

Test case code is attached.
Basically, main() is an endless loop that
	- creates two threads t1 & t2
	- joins t2
	- increments an iteration counter i.
t2 shall wait until t1 exists, then cancel and join t1.
t1 does nothing, but has a cleanup handler that increments a counter c.

When running without gdb, the output is as expected:
i=1, c=1, dt=0.000848
i=1001, c=1001, dt=0.095550
i=2001, c=2001, dt=0.081302
i=3001, c=3001, dt=0.089316
i=4001, c=4001, dt=0.088792
i=5001, c=5001, dt=0.086609
i=6001, c=6001, dt=0.086388
i=7001, c=7001, dt=0.090560
...

[ i: iteration, c: cancellation handler calls, dt: time ]

When running inside gdb (4.5 and master), I get:
i=1, c=1, dt=0.005421
i=1001, c=1000, dt=2.675437
i=2001, c=2000, dt=5.822094
i=3001, c=3000, dt=9.502770
i=4001, c=4000, dt=15.998418
i=5001, c=4999, dt=30.724420
i=6001, c=5999, dt=57.917127
i=7001, c=6999, dt=109.575370
i=8001, c=7999, dt=162.559419
i=9001, c=8999, dt=187.046422
...


First, c is not incremented for every iteration.
Maybe gdb inserts a cancellation point before the cleanup handler gets 
pushed ? Is this expected behavior ?

Second, the time per 1000 iterations increases rapidly.
I cannot figure a reason for that. Do you see this too ?

I am running this on ubuntu 12.04 64bit with eglibc-2.15 and gcc-4.6.3.

Thanks,
Mathis

#include <sys/types.h>
#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <errno.h>
#include <pthread.h>
#include <sys/time.h>

pthread_t t1;
pthread_t t2;
pthread_mutex_t m = PTHREAD_MUTEX_INITIALIZER;
int c;

void cancellation(void *nothing) {

  if (pthread_mutex_lock(&m)) 
  {
    printf("cancellation: lock error.\n");
    exit(1);
  }

  c++;

  if (pthread_mutex_unlock(&m)) 
  {
    printf("cancellation: unlock error.\n");
    exit(1);
  }

}

void *thread1(void *nothing) {
  pthread_cleanup_push(cancellation, NULL);

  while (1) 
  {
    usleep(10);
  }

  // never reached
  pthread_cleanup_pop(NULL);
  exit(5);
  return NULL;
}

void *thread2(void *nothing) {

  // wait until t1 is created
  pthread_mutex_lock(&m);
  pthread_mutex_unlock(&m);

  if (pthread_cancel(t1) != 0) 
  {
    printf("cancel error.\n");
    exit(1);
  }

  if (pthread_join(t1, NULL)) 
  {
    printf("join t1 error.\n");
    exit(1);
  }

  pthread_exit(NULL);
  return NULL;
}

int main(void) {

  int i = 0;
  struct timeval tv1, tv2, dt;

  printf("pid: %d\n", getpid());

  gettimeofday(&tv1, NULL);

  c=0;
  while (1) {

    if (pthread_mutex_lock(&m)) 
    {
      printf("lock error.\n");
      exit(1);
    }

    if ( pthread_create(&t1, NULL, thread1, NULL)
      || pthread_create(&t2, NULL, thread2, NULL)) 
    {
      printf("create error.\n");
      exit(1);
    }

    if (pthread_mutex_unlock(&m)) 
    {
      printf("unlock error.\n");
      exit(1);
    }

    if (pthread_join(t2, NULL)) 
    {
      printf("join t2 error.\n");
      exit(1);
    }

    if (i++ % 1000 == 0) 
    {
      gettimeofday(&tv2, NULL);
      timersub( &tv2, &tv1, &dt );
      printf("i=%d, c=%d, dt=%ld.%06ld\n", i, c, dt.tv_sec, dt.tv_usec);
      tv1 = tv2;
    }

  }

  return 0;
}