<commit_before>#include <sys/mman.h>
#include <stdio.h>
#include <string.h>
#include <stdlib.h>
#include <stdarg.h>
#include "pthreadP.h"
#include "pthread_log.h"
#include "semaphore.h"
#include <fcntl.h>
#include <unistd.h>

#include <shlib-compat.h>

// Turns debugging on and off
//#define DPRINT pthread_log_debug
#define DPRINT(x,...)

// Globals for user-level replay
int pthread_log_status = PTHREAD_LOG_NONE;
unsigned long* ppthread_log_clock = 0;

// System calls we added
#define __NR_pthread_print 	17
#define __NR_pthread_log        31
#define __NR_pthread_block      32
#define __NR_pthread_init       35
#define __NR_pthread_full       44
#define __NR_pthread_sysign     53
#define __NR_pthread_status     56
#define __NR_pthread_shm_path   98
#ifdef USE_EXTRA_DEBUG_LOG
#define __NR_pthread_extra_log  112
#endif

#define GET_OLD_STACKP()		__asm__ __volatile__ ("movl %%esp, %0\n\t": "=r" (head->old_stackp) : ) 
#define SET_NEW_STACKP()		__asm__ __volatile__ ("movl %0, %%esp\n\t" : : "r" (&(head->stack[DEFAULT_STACKSIZE-2048])))
#define RESET_OLD_STACKP()	__asm__ __volatile__ ("movl %0, %%esp\n\t" : : "r" (head->old_stackp)) 

// This prints a message outside of the record/replay mechanism - useful for debugging
void pthread_log_debug(const char* fmt,...)
{
    va_list ap;
    char buffer[256] = {0,};
    INTERNAL_SYSCALL_DECL(__err);
    va_start(ap,fmt);
    vsprintf(buffer,fmt,ap);
    INTERNAL_SYSCALL(pthread_print,__err,2,buffer,256);
    va_end(ap);
}

void pthread_log_stat (void)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_status,__err,1,&pthread_log_status);
}

// Kernel will set the recplay status.  Also tells the kernel where the replay clock lives
static void pthread_log_init (void)
{
    void* ppage;
    int fd;

    INTERNAL_SYSCALL_DECL(__err);
    fd = INTERNAL_SYSCALL(pthread_shm_path,__err,0);
    if (fd < 0) {
	pthread_log_debug("shm_open failed\n");
	exit (0);
    }
    
    ppage = mmap (0, 4096, PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0);
    DPRINT ("Initial mmap returns %p\n", ppage);

    if (ppage == MAP_FAILED) {
	pthread_log_debug ("Cannot setup shared page for clock\n");
	exit (0);
    }
    
    ppthread_log_clock = (unsigned long *) ppage;
    
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_init,__err,3,&pthread_log_status,(u_long)pthread_log_record,(u_long)pthread_log_replay);
}

// This informs the kernel about a newly allocated log
void pthread_log_alloc (struct pthread_log_head * log_addr, int* ignore_addr)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_log,__err,2,log_addr,ignore_addr);
}

// This informs the kernel about a thread blocking on user clock - returns when thread is unblocked
void pthread_log_block (u_long clock)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_block,__err,1,clock);
}

// This informs the kernel that the log is full
void pthread_log_full (void)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_full,__err,0);
}

// Fake syscall for signals delivered in ignored region
void pthread_sysign (void)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_sysign,__err,0);
}

#include <bits/libc-lock.h>

void pthread_log_mutex_lock_rec (__libc_lock_t* lock)
{
  pthread_log_record (0, LIBC_LOCK_LOCK_ENTER, (u_long) lock, 1); 
  __libc_lock_lock(*(lock));
  pthread_log_record (0, LIBC_LOCK_LOCK_EXIT, (u_long) lock, 0); 
}

void pthread_log_mutex_lock_rep (__libc_lock_t* lock)
{
  pthread_log_replay (LIBC_LOCK_LOCK_ENTER, (u_long) lock); 
  pthread_log_replay (LIBC_LOCK_LOCK_EXIT, (u_long) lock); 
}

void pthread_log_mutex_lock (__libc_lock_t* lock)
{
    if (is_recording()) { 
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	pthread_log_mutex_lock_rec (lock);
	RESET_OLD_STACKP(); 
    } else if (is_replaying()) {
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	pthread_log_mutex_lock_rep (lock);
	RESET_OLD_STACKP(); 
    } else {
	__libc_lock_lock(*(lock));
    }
}

int pthread_log_mutex_trylock_rec (__libc_lock_t* lock)
{
  int ret;
  pthread_log_record (0, LIBC_LOCK_TRYLOCK_ENTER, (u_long) lock, 1); 
  ret = __libc_lock_trylock(*(lock)); 
  pthread_log_record (ret, LIBC_LOCK_TRYLOCK_EXIT, (u_long) lock, 0); 
  return ret;
}

int pthread_log_mutex_trylock_rep (__libc_lock_t* lock)
{
  pthread_log_replay (LIBC_LOCK_TRYLOCK_ENTER, (u_long) lock); 
  return pthread_log_replay (LIBC_LOCK_TRYLOCK_EXIT, (u_long) lock); 
}

int pthread_log_mutex_trylock (__libc_lock_t* lock)
{
    int ret;		  
    if (is_recording()) { 
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	ret = pthread_log_mutex_trylock_rec (lock);
	RESET_OLD_STACKP(); 
    } else if (is_replaying()) { 
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	ret = pthread_log_mutex_trylock_rep (lock);
	RESET_OLD_STACKP(); 
    } else {
        ret = __libc_lock_trylock(*(lock)); 
    }								   
    return ret;							   
}

void pthread_log_mutex_unlock_rec (__libc_lock_t* lock)
{
  pthread_log_record (0, LIBC_LOCK_UNLOCK_ENTER, (u_long) lock, 1); 
  __libc_lock_unlock (*(lock));
  pthread_log_record (0, LIBC_LOCK_UNLOCK_EXIT, (u_long) lock, 0); 
}

void pthread_log_mutex_unlock_rep (__libc_lock_t* lock)
{
  pthread_log_replay (LIBC_LOCK_UNLOCK_ENTER, (u_long) lock); 
  pthread_log_replay (LIBC_LOCK_UNLOCK_EXIT, (u_long) lock); 
}

void pthread_log_mutex_unlock (__libc_lock_t* lock)
{
    if (is_recording()) { 
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	pthread_log_mutex_unlock_rec (lock);
	RESET_OLD_STACKP(); 
    } else if (is_replaying()) {
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	pthread_log_mutex_unlock_rep (lock);
	RESET_OLD_STACKP(); 
    } else {
	__libc_lock_unlock (*(lock));
    }
}

void (*pthread_log_lock)(int *);
int (*pthread_log_trylock)(int *);
void (*pthread_log_unlock)(int *);

extern void malloc_setup (void (*__pthread_log_lock)(int *),
			  int (*__pthread_log_trylock)(int *),
			  void (*__pthread_log_unlock)(int *));

// For debugging malloc issues - comment out for now
//extern void malloc_extra_setup (void (*__pthread_log_msg)(char *, int));

int check_recording (void) 
{
    struct pthread_log_head* head;

    if (pthread_log_status == PTHREAD_LOG_REP_AFTER_FORK) {
	// After a fork, we need to reload the log 
	head = THREAD_GETMEM (THREAD_SELF, log_head);
	pthread_log_full ();
#ifdef USE_DEBUG_LOG	
	head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
#else
	head->next = ((char *) head + sizeof (struct pthread_log_head));
	head->expected_clock = 0;
	head->num_expected_records = 0;
#endif
#ifdef USE_EXTRA_DEBUG_LOG
	{
	    INTERNAL_SYSCALL_DECL(__err);
	    INTERNAL_SYSCALL(pthread_extra_log,__err,2,1,0); // Log full
	    struct pthread_extra_log_head* ehead = THREAD_GETMEM (THREAD_SELF, extra_log_head);
	    ehead->next = (char *) ehead + sizeof (struct pthread_extra_log_head);
	}
#endif
	head->ignore_flag = 0;
	head->need_fake_calls = 0;
	DPRINT ("check_recording: head %p head->next %p\n", head, head->next);
	pthread_log_status = PTHREAD_LOG_REPLAY;
	return pthread_log_status;
    }

    // mcc: we need to get the status before allocating a log, so I've separated out
    // the status check with the log init. (This adds the cost of one more syscall on init)
    pthread_log_stat();

    if (pthread_log_status == PTHREAD_LOG_OFF)
	return PTHREAD_LOG_OFF;

    head = allocate_log();
    THREAD_SETMEM (THREAD_SELF, log_head, head);
    DPRINT ("Allocated log for main thread\n");
    pthread_log_alloc (head, &head->ignore_flag);
#ifdef USE_EXTRA_DEBUG_LOG
    {
	struct pthread_extra_log_head* ehead = allocate_extra_log ();
	THREAD_SETMEM (THREAD_SELF, extra_log_head, ehead);
	INTERNAL_SYSCALL_DECL(__err);
	INTERNAL_SYSCALL(pthread_extra_log,__err,2,0,ehead); // Register log allocation
    }
#endif
    head->ignore_flag = 1;
    pthread_log_init ();
    head->ignore_flag = 0;
    DPRINT ("Kernel sets log status to %d\n", pthread_log_status);
    malloc_setup(pthread_log_mutex_lock, pthread_log_mutex_trylock, pthread_log_mutex_unlock);
    //malloc_extra_setup(pthread_log_msg);

    DPRINT("end of check recording, head %p, pthread_log_status %d, ppthread_log_clock %p, *ppthread_log_clock %lu\n", head, pthread_log_status, ppthread_log_clock, *ppthread_log_clock);

    return pthread_log_status;
}

struct pthread_log_head *
allocate_log (void)
{
    struct pthread_log_head* head;
    u_long size = sizeof(struct pthread_log_head) + PTHREAD_LOG_SIZE;
    if (size % 4096) size += 4096 - (size%4096);
    head = (struct pthread_log_head *) mmap (0, size, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0);
    if (head == MAP_FAILED) {
	pthread_log_debug ("Unable to allocate thread log, errno is %d\n", errno);
	abort ();
    }
    head->ignore_flag = 0;
    head->need_fake_calls = 0;
#ifdef USE_DEBUG_LOG
    head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
    head->end = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head) + PTHREAD_LOG_SIZE);
#else
    head->next = ((char *) head + sizeof (struct pthread_log_head));
    head->end = ((char *) head + sizeof (struct pthread_log_head) + PTHREAD_LOG_SIZE);
    head->expected_clock = 0;
    head->num_expected_records = 0;
#endif

    // Note that there is allocated space left after end - we need this to handle variable-sized records
    return head;
}

void
register_log (void)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    pthread_log_alloc (head, &head->ignore_flag); 
#ifdef USE_EXTRA_DEBUG_LOG
   {
	struct pthread_extra_log_head* ehead = THREAD_GETMEM (THREAD_SELF, extra_log_head);
	INTERNAL_SYSCALL_DECL(__err);
	INTERNAL_SYSCALL(pthread_extra_log,__err,2,0,ehead); // Register log allocation
    }
#endif
    DPRINT ("Registered ignore flag at %p value %d\n", &head->ignore_flag, head->ignore_flag);
}

void
free_log (void)
{
    DPRINT ("Freed (not really - fixme) thread log\n");
}

#ifdef USE_DEBUG_LOG
void
pthread_log_record (int retval, unsigned long type, unsigned long check, int is_entry)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    struct pthread_log_data* data;
    int num_signals;

    if (head == NULL) return;
    if (head->need_fake_calls > 0) {
	// Some signals were delivered while we were ignoring syscalls
	// Add a record via recursive call to generate fake syscalls on replay
	num_signals = head->need_fake_calls;
	head->need_fake_calls = 0;

	data = head->next;
	data->retval = num_signals;
	data->type = FAKE_SYSCALLS;
	DPRINT ("Added fake record to log: num_signals %d\n", num_signals);
	(head->next)++; // Increment to next log record
	if (head->next == head->end) {
	    pthread_log_full();
	    head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
	}
    }
    data = head->next;
    data->clock = atomic_exchange_and_add (ppthread_log_clock, 1);
    data->retval = retval;
    data->type = type;
    data->check = check;
    data->errno = errno; // May have changed in ignore region
    head->ignore_flag = is_entry;
    DPRINT ("Added record to log: clock %lu retval %d type %lu check %lx\n", data->clock, data->retval, data->type, data->check);
    (head->next)++; // Increment to next log record
    if (head->next == head->end) {
	pthread_log_full();
	head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
    }
}

int 
pthread_log_replay (unsigned long type, unsigned long check)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    struct pthread_log_data* data;
    int i, retval;

    if (head == NULL) return 0;
    data = head->next;

    DPRINT ("Read record from log: clock %lu, retval %d, type %lu, check %lx\n", data->clock, data->retval, data->type, data->check);

    if (data->type == 0) { // We've reached the end of the log - some other thread may be able to run, though
	pthread_log_block (INT_MAX); 
    }
    while (data->type == FAKE_SYSCALLS) {
	(head->next)++; // Increment to next log record
	if (head->next == head->end) {
	    DPRINT ("Log is full - need to reload\n");
	    pthread_log_full ();
	    head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
	}
	// Make the specified number of fake syscalls to sequence signals correctly
	for (i = 0; i < data->retval; i++) {
	    pthread_sysign ();
	}
	// New should be able to consider the next record (after ones handled by signhandler)
	data = head->next;
    }

    if (data->check != check || data->type != type) {
	pthread_log_debug ("Replay mismatch: log record %lu has type %lu check %x - but called with type %lu check %lx\n", data->clock, data->type, data->check, type, check);
	pthread_log_debug ("Callee 0 is 0x%p\n", __builtin_return_address(0));
	pthread_log_debug ("Callee 1 is 0x%p\n", __builtin_return_address(1));
	pthread_log_debug ("Callee 2 is 0x%p\n", __builtin_return_address(2));
	pthread_log_debug ("Callee 3 is 0x%p\n", __builtin_return_address(3));
	exit (0);
    }

    while (*ppthread_log_clock < data->clock) {
	pthread_log_block (data->clock); // Kernel will block us until we can run again
    }
    (*ppthread_log_clock)++;
    DPRINT ("Replay clock incremented to %d\n", *ppthread_log_clock);
    errno = data->errno;
    retval = data->retval;
    (head->next)++; // Increment to next log record
    if (head->next == head->end) {
	DPRINT ("Log is full - need to reload\n");
	pthread_log_full ();
	head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
    }

    return retval;
}

#else
void
pthread_log_record (int retval, unsigned long type, unsigned long check, int is_entry)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    unsigned long new_clock, delta_clock, log_entry;

    if (head == NULL) return;

    new_clock = atomic_exchange_and_add (ppthread_log_clock, 1);
    delta_clock = new_clock - head->expected_clock; // Store delta-1, not absolute value
    head->expected_clock = new_clock + 1;

    if (is_entry) head->save_errno = errno;

    if (retval == 0 && head->need_fake_calls == 0 && delta_clock == 0) {
	head->num_expected_records++;
    } else {
	log_entry = head->num_expected_records; // XXX - assume that this value not greater than CLOCK_MASK
	if (retval) log_entry |= NONZERO_RETVAL_FLAG;
	if (head->need_fake_calls > 0) log_entry |= FAKE_CALLS_FLAG;
	if (delta_clock) log_entry |= SKIPPED_CLOCK_FLAG;
	if (!is_entry && errno != head->save_errno) log_entry |= ERRNO_CHANGE_FLAG;

	*((int *) head->next) = log_entry;
	head->next += sizeof(int);

	if (delta_clock) {
	    *((int *) head->next) = delta_clock;
	    head->next += sizeof(unsigned long);
	}
	    
	if (retval) {
	    *((int *) head->next) = retval;
	    head->next += sizeof(int);
	}

	if (!is_entry && errno != head->save_errno) {
	    *((int *) head->next) = errno;
	    head->next += sizeof(int);
	}

	if (head->need_fake_calls > 0) {
	    // Some signals were delivered while we were ignoring syscalls
	    // Add a record via recursive call to generate fake syscalls on replay
	    *((int *) head->next) = head->need_fake_calls;
	    head->need_fake_calls = 0;
	    head->next += sizeof(int);
	}

	if (head->next >= head->end) {
	    pthread_log_full();
	    head->next = ((char *) head + sizeof (struct pthread_log_head));
	}
	head->num_expected_records = 0;
    }

    head->ignore_flag = is_entry;
    DPRINT ("Added record to log: clock %lu retval %d type %lu check %lx errno %d\n", new_clock, retval, type, check, errno);
}

int 
pthread_log_replay (unsigned long type, unsigned long check)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    unsigned long* pentry;
    unsigned long next_clock;
    int num_fake_calls, i, retval;

    if (head == NULL) return 0;

    if (head->num_expected_records > 1) {
	head->expected_clock++;
	(*ppthread_log_clock)++;
	DPRINT ("Replay clock auto-incremented (1) to %d\n", *ppthread_log_clock);
	head->num_expected_records--;
	return 0;
    } 

    pentry = (unsigned long *) head->next;
    
    if (head->num_expected_records == 0) {
	// Only do these things on a *newly read* record
	DPRINT ("Read entry from log: %lx\n", *pentry);

	if (*pentry == 0) { // We've reached the end of the log - some other thread may be able to run, though
	    pthread_log_block (INT_MAX); 
	}
	head->num_expected_records = (*pentry & CLOCK_MASK);
	if (head->num_expected_records) {
	    head->expected_clock++;
	    (*ppthread_log_clock)++;
	    DPRINT ("Replay clock auto-incremented (2) to %d\n", *ppthread_log_clock);
	    return 0;
	}
    }

    head->next += sizeof(unsigned long); // Consume entry since all expected records are done
    head->num_expected_records = 0;

    next_clock = head->expected_clock;
    if (*pentry & SKIPPED_CLOCK_FLAG) {
	next_clock += *((int *)head->next);
	head->next += sizeof(unsigned long);
    }

    if (*pentry & NONZERO_RETVAL_FLAG) {
	retval = *((int *)head->next);
	head->next += sizeof(int);
    } else {
	retval = 0;
    }

    if (*pentry & ERRNO_CHANGE_FLAG) {
	errno = *((int *)head->next);
	head->next += sizeof(int);
    }

    if (*pentry & FAKE_CALLS_FLAG) {
	num_fake_calls = *((int *)head->next);
	head->next += sizeof(int);

	// Make the specified number of fake syscalls to sequence signals correctly
	for (i = 0; i < num_fake_calls; i++) pthread_sysign ();
    }

    while (*ppthread_log_clock < next_clock) {
	DPRINT ("waiting for clock %lu\n", next_clock);
	pthread_log_block (next_clock); // Kernel will block us until we can run again
    }
    head->expected_clock = next_clock + 1;
    (*ppthread_log_clock)++;
    DPRINT ("Replay clock incremented to %d\n", *ppthread_log_clock);
    
    if (head->next >= head->end) {
	DPRINT ("Log is full - need to reload\n");
	pthread_log_full ();
	head->next = ((char *) head + sizeof (struct pthread_log_head));
    }

    return retval;
}
#endif

#ifdef USE_EXTRA_DEBUG_LOG
struct pthread_extra_log_head *
allocate_extra_log (void)
{
    struct pthread_extra_log_head* head;
    u_long size = sizeof(struct pthread_extra_log_head) + PTHREAD_LOG_SIZE;
    if (size % 4096) size += 4096 - (size%4096);
    head = (struct pthread_extra_log_head *) mmap (0, size, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0);
    if (head == MAP_FAILED) {
	pthread_log_debug ("Unable to allocate extra thread log, errno is %d\n", errno);
	abort ();
    }
    head->next = ((char *) head + sizeof (struct pthread_extra_log_head));
    head->end =  ((char *) head + sizeof (struct pthread_extra_log_head) + PTHREAD_LOG_SIZE);

    return head;
}

void
pthread_extra_log_record (char* msg, int len)
{
    struct pthread_extra_log_head* head = THREAD_GETMEM (THREAD_SELF, extra_log_head);
    char* data;

    if (head == NULL) return;
    if (head->next + sizeof(u_long) + len >= head->end) {
	INTERNAL_SYSCALL_DECL(__err);
	INTERNAL_SYSCALL(pthread_extra_log,__err,2,1,0); // Log full
	head->next = ((char *) head + sizeof (struct pthread_extra_log_head));
    }	
    data = head->next;
    *((u_long *) data) = *ppthread_log_clock;
    data += sizeof(u_long);
    memcpy (data, msg, len);
    data += len;
    head->next = data;
}

int
pthread_extra_log_replay (char* msg, int len)
{
    struct pthread_extra_log_head* head = THREAD_GETMEM (THREAD_SELF, extra_log_head);
    char* data;
    u_long log_clock;
    int i;
    int rc = 0;

    if (head == NULL) return 0;
    if (head->next + sizeof(u_long) + len >= head->end) {
	INTERNAL_SYSCALL_DECL(__err);
	INTERNAL_SYSCALL(pthread_extra_log,__err,2,1,0); // Log full
	head->next = ((char *) head + sizeof (struct pthread_extra_log_head));
    }
    data = head->next;
    log_clock = *((u_long *) data);
    data += sizeof(u_long);
    if (*ppthread_log_clock != log_clock) {
	pthread_log_debug ("extra log clock difference: record %lx replay %lx\n", log_clock, *ppthread_log_clock);
	rc = -1;
    }
    if (memcmp (msg, data, len)) {
	pthread_log_debug ("extra log message difference\n");
	for (i = 0; i < len; i += 4) {
	    pthread_log_debug ("byte %d record %lx replay %lx\n", i, *((u_long *) &data[i]), *((u_long *) &msg[i]));
	}
	rc = -1;
    }
    data += len;
    head->next = data;
    return rc;
}

int
pthread_log_msg (char* msg, int len)
{
    int ret = 0;
    if (is_recording()) {
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	pthread_extra_log_record (msg, len);
	RESET_OLD_STACKP(); 
    } else if (is_replaying()) {
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	ret = pthread_extra_log_replay (msg, len);
	RESET_OLD_STACKP(); 
    }
    return ret;
}

#endif

int
pthread_mutex_consistent_rec (mutex) 
     pthread_mutex_t *mutex;
{
  int rc;
  pthread_log_record (0, PTHREAD_MUTEX_CONSISTENT_ENTER, (u_long) mutex, 1); <commit_msg>Need to change how extra log does the stack switch.<commit_after>#include <sys/mman.h>
#include <stdio.h>
#include <string.h>
#include <stdlib.h>
#include <stdarg.h>
#include "pthreadP.h"
#include "pthread_log.h"
#include "semaphore.h"
#include <fcntl.h>
#include <unistd.h>

#include <shlib-compat.h>

// Turns debugging on and off
//#define DPRINT pthread_log_debug
#define DPRINT(x,...)

// Globals for user-level replay
int pthread_log_status = PTHREAD_LOG_NONE;
unsigned long* ppthread_log_clock = 0;

// System calls we added
#define __NR_pthread_print 	17
#define __NR_pthread_log        31
#define __NR_pthread_block      32
#define __NR_pthread_init       35
#define __NR_pthread_full       44
#define __NR_pthread_sysign     53
#define __NR_pthread_status     56
#define __NR_pthread_shm_path   98
#ifdef USE_EXTRA_DEBUG_LOG
#define __NR_pthread_extra_log  112
#endif

#define GET_OLD_STACKP()		__asm__ __volatile__ ("movl %%esp, %0\n\t": "=r" (head->old_stackp) : ) 
#define SET_NEW_STACKP()		__asm__ __volatile__ ("movl %0, %%esp\n\t" : : "r" (&(head->stack[DEFAULT_STACKSIZE-2048])))
#define RESET_OLD_STACKP()	__asm__ __volatile__ ("movl %0, %%esp\n\t" : : "r" (head->old_stackp)) 

// This prints a message outside of the record/replay mechanism - useful for debugging
void pthread_log_debug(const char* fmt,...)
{
    va_list ap;
    char buffer[256] = {0,};
    INTERNAL_SYSCALL_DECL(__err);
    va_start(ap,fmt);
    vsprintf(buffer,fmt,ap);
    INTERNAL_SYSCALL(pthread_print,__err,2,buffer,256);
    va_end(ap);
}

void pthread_log_stat (void)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_status,__err,1,&pthread_log_status);
}

// Kernel will set the recplay status.  Also tells the kernel where the replay clock lives
static void pthread_log_init (void)
{
    void* ppage;
    int fd;

    INTERNAL_SYSCALL_DECL(__err);
    fd = INTERNAL_SYSCALL(pthread_shm_path,__err,0);
    if (fd < 0) {
	pthread_log_debug("shm_open failed\n");
	exit (0);
    }
    
    ppage = mmap (0, 4096, PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0);
    DPRINT ("Initial mmap returns %p\n", ppage);

    if (ppage == MAP_FAILED) {
	pthread_log_debug ("Cannot setup shared page for clock\n");
	exit (0);
    }
    
    ppthread_log_clock = (unsigned long *) ppage;
    
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_init,__err,3,&pthread_log_status,(u_long)pthread_log_record,(u_long)pthread_log_replay);
}

// This informs the kernel about a newly allocated log
void pthread_log_alloc (struct pthread_log_head * log_addr, int* ignore_addr)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_log,__err,2,log_addr,ignore_addr);
}

// This informs the kernel about a thread blocking on user clock - returns when thread is unblocked
void pthread_log_block (u_long clock)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_block,__err,1,clock);
}

// This informs the kernel that the log is full
void pthread_log_full (void)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_full,__err,0);
}

// Fake syscall for signals delivered in ignored region
void pthread_sysign (void)
{
    INTERNAL_SYSCALL_DECL(__err);
    INTERNAL_SYSCALL(pthread_sysign,__err,0);
}

#include <bits/libc-lock.h>

void pthread_log_mutex_lock_rec (__libc_lock_t* lock)
{
  pthread_log_record (0, LIBC_LOCK_LOCK_ENTER, (u_long) lock, 1); 
  __libc_lock_lock(*(lock));
  pthread_log_record (0, LIBC_LOCK_LOCK_EXIT, (u_long) lock, 0); 
}

void pthread_log_mutex_lock_rep (__libc_lock_t* lock)
{
  pthread_log_replay (LIBC_LOCK_LOCK_ENTER, (u_long) lock); 
  pthread_log_replay (LIBC_LOCK_LOCK_EXIT, (u_long) lock); 
}

void pthread_log_mutex_lock (__libc_lock_t* lock)
{
    if (is_recording()) { 
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	pthread_log_mutex_lock_rec (lock);
	RESET_OLD_STACKP(); 
    } else if (is_replaying()) {
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	pthread_log_mutex_lock_rep (lock);
	RESET_OLD_STACKP(); 
    } else {
	__libc_lock_lock(*(lock));
    }
}

int pthread_log_mutex_trylock_rec (__libc_lock_t* lock)
{
  int ret;
  pthread_log_record (0, LIBC_LOCK_TRYLOCK_ENTER, (u_long) lock, 1); 
  ret = __libc_lock_trylock(*(lock)); 
  pthread_log_record (ret, LIBC_LOCK_TRYLOCK_EXIT, (u_long) lock, 0); 
  return ret;
}

int pthread_log_mutex_trylock_rep (__libc_lock_t* lock)
{
  pthread_log_replay (LIBC_LOCK_TRYLOCK_ENTER, (u_long) lock); 
  return pthread_log_replay (LIBC_LOCK_TRYLOCK_EXIT, (u_long) lock); 
}

int pthread_log_mutex_trylock (__libc_lock_t* lock)
{
    int ret;		  
    if (is_recording()) { 
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	ret = pthread_log_mutex_trylock_rec (lock);
	RESET_OLD_STACKP(); 
    } else if (is_replaying()) { 
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	ret = pthread_log_mutex_trylock_rep (lock);
	RESET_OLD_STACKP(); 
    } else {
        ret = __libc_lock_trylock(*(lock)); 
    }								   
    return ret;							   
}

void pthread_log_mutex_unlock_rec (__libc_lock_t* lock)
{
  pthread_log_record (0, LIBC_LOCK_UNLOCK_ENTER, (u_long) lock, 1); 
  __libc_lock_unlock (*(lock));
  pthread_log_record (0, LIBC_LOCK_UNLOCK_EXIT, (u_long) lock, 0); 
}

void pthread_log_mutex_unlock_rep (__libc_lock_t* lock)
{
  pthread_log_replay (LIBC_LOCK_UNLOCK_ENTER, (u_long) lock); 
  pthread_log_replay (LIBC_LOCK_UNLOCK_EXIT, (u_long) lock); 
}

void pthread_log_mutex_unlock (__libc_lock_t* lock)
{
    if (is_recording()) { 
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	pthread_log_mutex_unlock_rec (lock);
	RESET_OLD_STACKP(); 
    } else if (is_replaying()) {
	struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
	GET_OLD_STACKP();
	SET_NEW_STACKP();
	pthread_log_mutex_unlock_rep (lock);
	RESET_OLD_STACKP(); 
    } else {
	__libc_lock_unlock (*(lock));
    }
}

void (*pthread_log_lock)(int *);
int (*pthread_log_trylock)(int *);
void (*pthread_log_unlock)(int *);

extern void malloc_setup (void (*__pthread_log_lock)(int *),
			  int (*__pthread_log_trylock)(int *),
			  void (*__pthread_log_unlock)(int *));

// For debugging malloc issues - comment out for now
//extern void malloc_extra_setup (void (*__pthread_log_msg)(char *, int));

int check_recording (void) 
{
    struct pthread_log_head* head;

    if (pthread_log_status == PTHREAD_LOG_REP_AFTER_FORK) {
	// After a fork, we need to reload the log 
	head = THREAD_GETMEM (THREAD_SELF, log_head);
	pthread_log_full ();
#ifdef USE_DEBUG_LOG	
	head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
#else
	head->next = ((char *) head + sizeof (struct pthread_log_head));
	head->expected_clock = 0;
	head->num_expected_records = 0;
#endif
#ifdef USE_EXTRA_DEBUG_LOG
	{
	    INTERNAL_SYSCALL_DECL(__err);
	    INTERNAL_SYSCALL(pthread_extra_log,__err,2,1,0); // Log full
	    struct pthread_extra_log_head* ehead = THREAD_GETMEM (THREAD_SELF, extra_log_head);
	    ehead->next = (char *) ehead + sizeof (struct pthread_extra_log_head);
	}
#endif
	head->ignore_flag = 0;
	head->need_fake_calls = 0;
	DPRINT ("check_recording: head %p head->next %p\n", head, head->next);
	pthread_log_status = PTHREAD_LOG_REPLAY;
	return pthread_log_status;
    }

    // mcc: we need to get the status before allocating a log, so I've separated out
    // the status check with the log init. (This adds the cost of one more syscall on init)
    pthread_log_stat();

    if (pthread_log_status == PTHREAD_LOG_OFF)
	return PTHREAD_LOG_OFF;

    head = allocate_log();
    THREAD_SETMEM (THREAD_SELF, log_head, head);
    DPRINT ("Allocated log for main thread\n");
    pthread_log_alloc (head, &head->ignore_flag);
#ifdef USE_EXTRA_DEBUG_LOG
    {
	struct pthread_extra_log_head* ehead = allocate_extra_log ();
	THREAD_SETMEM (THREAD_SELF, extra_log_head, ehead);
	INTERNAL_SYSCALL_DECL(__err);
	INTERNAL_SYSCALL(pthread_extra_log,__err,2,0,ehead); // Register log allocation
    }
#endif
    head->ignore_flag = 1;
    pthread_log_init ();
    head->ignore_flag = 0;
    DPRINT ("Kernel sets log status to %d\n", pthread_log_status);
    malloc_setup(pthread_log_mutex_lock, pthread_log_mutex_trylock, pthread_log_mutex_unlock);
    //malloc_extra_setup(pthread_log_msg);

    DPRINT("end of check recording, head %p, pthread_log_status %d, ppthread_log_clock %p, *ppthread_log_clock %lu\n", head, pthread_log_status, ppthread_log_clock, *ppthread_log_clock);

    return pthread_log_status;
}

struct pthread_log_head *
allocate_log (void)
{
    struct pthread_log_head* head;
    u_long size = sizeof(struct pthread_log_head) + PTHREAD_LOG_SIZE;
    if (size % 4096) size += 4096 - (size%4096);
    head = (struct pthread_log_head *) mmap (0, size, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0);
    if (head == MAP_FAILED) {
	pthread_log_debug ("Unable to allocate thread log, errno is %d\n", errno);
	abort ();
    }
    head->ignore_flag = 0;
    head->need_fake_calls = 0;
#ifdef USE_DEBUG_LOG
    head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
    head->end = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head) + PTHREAD_LOG_SIZE);
#else
    head->next = ((char *) head + sizeof (struct pthread_log_head));
    head->end = ((char *) head + sizeof (struct pthread_log_head) + PTHREAD_LOG_SIZE);
    head->expected_clock = 0;
    head->num_expected_records = 0;
#endif

    // Note that there is allocated space left after end - we need this to handle variable-sized records
    return head;
}

void
register_log (void)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    pthread_log_alloc (head, &head->ignore_flag); 
#ifdef USE_EXTRA_DEBUG_LOG
   {
	struct pthread_extra_log_head* ehead = THREAD_GETMEM (THREAD_SELF, extra_log_head);
	INTERNAL_SYSCALL_DECL(__err);
	INTERNAL_SYSCALL(pthread_extra_log,__err,2,0,ehead); // Register log allocation
    }
#endif
    DPRINT ("Registered ignore flag at %p value %d\n", &head->ignore_flag, head->ignore_flag);
}

void
free_log (void)
{
    DPRINT ("Freed (not really - fixme) thread log\n");
}

#ifdef USE_DEBUG_LOG
void
pthread_log_record (int retval, unsigned long type, unsigned long check, int is_entry)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    struct pthread_log_data* data;
    int num_signals;

    if (head == NULL) return;
    if (head->need_fake_calls > 0) {
	// Some signals were delivered while we were ignoring syscalls
	// Add a record via recursive call to generate fake syscalls on replay
	num_signals = head->need_fake_calls;
	head->need_fake_calls = 0;

	data = head->next;
	data->retval = num_signals;
	data->type = FAKE_SYSCALLS;
	DPRINT ("Added fake record to log: num_signals %d\n", num_signals);
	(head->next)++; // Increment to next log record
	if (head->next == head->end) {
	    pthread_log_full();
	    head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
	}
    }
    data = head->next;
    data->clock = atomic_exchange_and_add (ppthread_log_clock, 1);
    data->retval = retval;
    data->type = type;
    data->check = check;
    data->errno = errno; // May have changed in ignore region
    head->ignore_flag = is_entry;
    DPRINT ("Added record to log: clock %lu retval %d type %lu check %lx\n", data->clock, data->retval, data->type, data->check);
    (head->next)++; // Increment to next log record
    if (head->next == head->end) {
	pthread_log_full();
	head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
    }
}

int 
pthread_log_replay (unsigned long type, unsigned long check)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    struct pthread_log_data* data;
    int i, retval;

    if (head == NULL) return 0;
    data = head->next;

    DPRINT ("Read record from log: clock %lu, retval %d, type %lu, check %lx\n", data->clock, data->retval, data->type, data->check);

    if (data->type == 0) { // We've reached the end of the log - some other thread may be able to run, though
	pthread_log_block (INT_MAX); 
    }
    while (data->type == FAKE_SYSCALLS) {
	(head->next)++; // Increment to next log record
	if (head->next == head->end) {
	    DPRINT ("Log is full - need to reload\n");
	    pthread_log_full ();
	    head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
	}
	// Make the specified number of fake syscalls to sequence signals correctly
	for (i = 0; i < data->retval; i++) {
	    pthread_sysign ();
	}
	// New should be able to consider the next record (after ones handled by signhandler)
	data = head->next;
    }

    if (data->check != check || data->type != type) {
	pthread_log_debug ("Replay mismatch: log record %lu has type %lu check %x - but called with type %lu check %lx\n", data->clock, data->type, data->check, type, check);
	pthread_log_debug ("Callee 0 is 0x%p\n", __builtin_return_address(0));
	pthread_log_debug ("Callee 1 is 0x%p\n", __builtin_return_address(1));
	pthread_log_debug ("Callee 2 is 0x%p\n", __builtin_return_address(2));
	pthread_log_debug ("Callee 3 is 0x%p\n", __builtin_return_address(3));
	exit (0);
    }

    while (*ppthread_log_clock < data->clock) {
	pthread_log_block (data->clock); // Kernel will block us until we can run again
    }
    (*ppthread_log_clock)++;
    DPRINT ("Replay clock incremented to %d\n", *ppthread_log_clock);
    errno = data->errno;
    retval = data->retval;
    (head->next)++; // Increment to next log record
    if (head->next == head->end) {
	DPRINT ("Log is full - need to reload\n");
	pthread_log_full ();
	head->next = (struct pthread_log_data *) ((char *) head + sizeof (struct pthread_log_head));
    }

    return retval;
}

#else
void
pthread_log_record (int retval, unsigned long type, unsigned long check, int is_entry)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    unsigned long new_clock, delta_clock, log_entry;

    if (head == NULL) return;

    new_clock = atomic_exchange_and_add (ppthread_log_clock, 1);
    delta_clock = new_clock - head->expected_clock; // Store delta-1, not absolute value
    head->expected_clock = new_clock + 1;

    if (is_entry) head->save_errno = errno;

    if (retval == 0 && head->need_fake_calls == 0 && delta_clock == 0) {
	head->num_expected_records++;
    } else {
	log_entry = head->num_expected_records; // XXX - assume that this value not greater than CLOCK_MASK
	if (retval) log_entry |= NONZERO_RETVAL_FLAG;
	if (head->need_fake_calls > 0) log_entry |= FAKE_CALLS_FLAG;
	if (delta_clock) log_entry |= SKIPPED_CLOCK_FLAG;
	if (!is_entry && errno != head->save_errno) log_entry |= ERRNO_CHANGE_FLAG;

	*((int *) head->next) = log_entry;
	head->next += sizeof(int);

	if (delta_clock) {
	    *((int *) head->next) = delta_clock;
	    head->next += sizeof(unsigned long);
	}
	    
	if (retval) {
	    *((int *) head->next) = retval;
	    head->next += sizeof(int);
	}

	if (!is_entry && errno != head->save_errno) {
	    *((int *) head->next) = errno;
	    head->next += sizeof(int);
	}

	if (head->need_fake_calls > 0) {
	    // Some signals were delivered while we were ignoring syscalls
	    // Add a record via recursive call to generate fake syscalls on replay
	    *((int *) head->next) = head->need_fake_calls;
	    head->need_fake_calls = 0;
	    head->next += sizeof(int);
	}

	if (head->next >= head->end) {
	    pthread_log_full();
	    head->next = ((char *) head + sizeof (struct pthread_log_head));
	}
	head->num_expected_records = 0;
    }

    head->ignore_flag = is_entry;
    DPRINT ("Added record to log: clock %lu retval %d type %lu check %lx errno %d\n", new_clock, retval, type, check, errno);
}

int 
pthread_log_replay (unsigned long type, unsigned long check)
{
    struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
    unsigned long* pentry;
    unsigned long next_clock;
    int num_fake_calls, i, retval;

    if (head == NULL) return 0;

    if (head->num_expected_records > 1) {
	head->expected_clock++;
	(*ppthread_log_clock)++;
	DPRINT ("Replay clock auto-incremented (1) to %d\n", *ppthread_log_clock);
	head->num_expected_records--;
	return 0;
    } 

    pentry = (unsigned long *) head->next;
    
    if (head->num_expected_records == 0) {
	// Only do these things on a *newly read* record
	DPRINT ("Read entry from log: %lx\n", *pentry);

	if (*pentry == 0) { // We've reached the end of the log - some other thread may be able to run, though
	    pthread_log_block (INT_MAX); 
	}
	head->num_expected_records = (*pentry & CLOCK_MASK);
	if (head->num_expected_records) {
	    head->expected_clock++;
	    (*ppthread_log_clock)++;
	    DPRINT ("Replay clock auto-incremented (2) to %d\n", *ppthread_log_clock);
	    return 0;
	}
    }

    head->next += sizeof(unsigned long); // Consume entry since all expected records are done
    head->num_expected_records = 0;

    next_clock = head->expected_clock;
    if (*pentry & SKIPPED_CLOCK_FLAG) {
	next_clock += *((int *)head->next);
	head->next += sizeof(unsigned long);
    }

    if (*pentry & NONZERO_RETVAL_FLAG) {
	retval = *((int *)head->next);
	head->next += sizeof(int);
    } else {
	retval = 0;
    }

    if (*pentry & ERRNO_CHANGE_FLAG) {
	errno = *((int *)head->next);
	head->next += sizeof(int);
    }

    if (*pentry & FAKE_CALLS_FLAG) {
	num_fake_calls = *((int *)head->next);
	head->next += sizeof(int);

	// Make the specified number of fake syscalls to sequence signals correctly
	for (i = 0; i < num_fake_calls; i++) pthread_sysign ();
    }

    while (*ppthread_log_clock < next_clock) {
	DPRINT ("waiting for clock %lu\n", next_clock);
	pthread_log_block (next_clock); // Kernel will block us until we can run again
    }
    head->expected_clock = next_clock + 1;
    (*ppthread_log_clock)++;
    DPRINT ("Replay clock incremented to %d\n", *ppthread_log_clock);
    
    if (head->next >= head->end) {
	DPRINT ("Log is full - need to reload\n");
	pthread_log_full ();
	head->next = ((char *) head + sizeof (struct pthread_log_head));
    }

    return retval;
}
#endif

#ifdef USE_EXTRA_DEBUG_LOG
struct pthread_extra_log_head *
allocate_extra_log (void)
{
    struct pthread_extra_log_head* head;
    u_long size = sizeof(struct pthread_extra_log_head) + PTHREAD_LOG_SIZE;
    if (size % 4096) size += 4096 - (size%4096);
    head = (struct pthread_extra_log_head *) mmap (0, size, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0);
    if (head == MAP_FAILED) {
	pthread_log_debug ("Unable to allocate extra thread log, errno is %d\n", errno);
	abort ();
    }
    head->next = ((char *) head + sizeof (struct pthread_extra_log_head));
    head->end =  ((char *) head + sizeof (struct pthread_extra_log_head) + PTHREAD_LOG_SIZE);

    return head;
}

void
pthread_extra_log_record (char* msg, int len)
{
    struct pthread_extra_log_head* head = THREAD_GETMEM (THREAD_SELF, extra_log_head);
    char* data;

    if (head == NULL) return;
    if (head->next + sizeof(u_long) + len >= head->end) {
	INTERNAL_SYSCALL_DECL(__err);
	INTERNAL_SYSCALL(pthread_extra_log,__err,2,1,0); // Log full
	head->next = ((char *) head + sizeof (struct pthread_extra_log_head));
    }	
    data = head->next;
    *((u_long *) data) = *ppthread_log_clock;
    data += sizeof(u_long);
    memcpy (data, msg, len);
    data += len;
    head->next = data;
}

int
pthread_extra_log_replay (char* msg, int len)
{
    struct pthread_extra_log_head* head = THREAD_GETMEM (THREAD_SELF, extra_log_head);
    char* data;
    u_long log_clock;
    int i;
    int rc = 0;

    if (head == NULL) return 0;
    if (head->next + sizeof(u_long) + len >= head->end) {
	INTERNAL_SYSCALL_DECL(__err);
	INTERNAL_SYSCALL(pthread_extra_log,__err,2,1,0); // Log full
	head->next = ((char *) head + sizeof (struct pthread_extra_log_head));
    }
    data = head->next;
    log_clock = *((u_long *) data);
    data += sizeof(u_long);
    if (*ppthread_log_clock != log_clock) {
	pthread_log_debug ("extra log clock difference: record %lx replay %lx\n", log_clock, *ppthread_log_clock);
	rc = -1;
    }
    if (memcmp (msg, data, len)) {
	pthread_log_debug ("extra log message difference\n");
	for (i = 0; i < len; i += 4) {
	    pthread_log_debug ("byte %d record %lx replay %lx\n", i, *((u_long *) &data[i]), *((u_long *) &msg[i]));
	}
	rc = -1;
    }
    data += len;
    head->next = data;
    return rc;
}

void pthread_log_msg_dummy (char* msg, int len)
{
}

int
pthread_log_msg (char* msg, int len)
{
    int ret = 0;
    if (is_recording()) {
      struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
      GET_OLD_STACKP();
      SET_NEW_STACKP();
      pthread_extra_log_record (msg, len);
      RESET_OLD_STACKP(); 
    } else if (is_replaying()) {
      struct pthread_log_head* head = THREAD_GETMEM (THREAD_SELF, log_head);
      GET_OLD_STACKP();
      SET_NEW_STACKP();
      ret = pthread_extra_log_replay (msg, len);
      RESET_OLD_STACKP(); 
    } else {
      pthread_log_msg_dummy (msg, len);
    }
    return ret;
}

#endif

int
pthread_mutex_consistent_rec (mutex) 
     pthread_mutex_t *mutex;
{
  int rc;
  pthread_log_record (0, PTHREAD_MUTEX_CONSISTENT_ENTER, (u_long) mutex, 1); 
{'fraction_non_alphanumeric': 0.12666107147852845, 'fraction_numerical': 0.007693383690026577, 'mean_word_length': 4.154409997596732, 'pattern_counts': {'":': 2, '<': 33, '<?xml version=': 0, '>': 315, 'https://': 0, 'lorem ipsum': 0, 'www.': 0, 'xml': 0}, 'pii_count': 0, 'substrings_counts': 0, 'word_list_counts': {'cursed_substrings.json': 0, 'profanity_word_list.json': 0, 'sexual_word_list.json': 0, 'zh_pornsignals.json': 0}}
{'dir': 'git-commits-cleaned', 'id': '7033700', 'n_tokens_mistral': 16382, 'n_tokens_neox': 15757, 'n_words': 3785}