[ccache] PATCH: Add cwd/hostname to logfiles

2010-05-06 Thread Wilson Snyder

I'm debugging a problem which will be the topic of the next
mail.  To do this, I needed the cwd of the compile, and
hostname printed in the logfile, otherwise it's impossible
to sort out parallel builds; a patch for this is below.

I also found the timestamp useful, but have this as a
separate patch as it may be less worth adding and it
probably needs work for portability.  I won't loose sleep
if you want to reject it.

These are against trunk.

From 489d53e4a6b0c4497f389b2e6dcc1b3e4bcef1d1 Mon Sep 17 00:00:00 2001
From: Wilson Snyder wsny...@wsnyder.org
Date: Thu, 6 May 2010 10:13:03 -0400
Subject: [PATCH 1/2] Show hostname and CWD in logfile

---
 ccache.c |4 
 ccache.h |1 +
 util.c   |   25 +++--
 3 files changed, 24 insertions(+), 6 deletions(-)

diff --git a/ccache.c b/ccache.c
index cbbfdc8..ba3b6ad 100644
--- a/ccache.c
+++ b/ccache.c
@@ -1673,6 +1673,10 @@ static void ccache(int argc, char *argv[])
process_args(orig_args-argc, orig_args-argv, preprocessor_args,
 compiler_args);
 
+   cc_log(Hostname: %s, get_hostname());
+
+   cc_log(Cwd: %s, current_working_dir);
+
cc_log(Source file: %s, input_file);
if (generating_dependencies) {
cc_log(Dependency file: %s, output_dep);
diff --git a/ccache.h b/ccache.h
index f514057..2277344 100644
--- a/ccache.h
+++ b/ccache.h
@@ -73,6 +73,7 @@ int move_file(const char *src, const char *dest, int 
compress_dest);
 int test_if_compressed(const char *filename);
 
 int create_dir(const char *dir);
+const char *get_hostname(void);
 const char *tmp_string(void);
 char *format_hash_as_string(const unsigned char *hash, unsigned size);
 int create_hash_dir(char **dir, const char *hash, const char *cache_dir);
diff --git a/util.c b/util.c
index 34f1b5e..c50a7d5 100644
--- a/util.c
+++ b/util.c
@@ -272,6 +272,24 @@ int create_dir(const char *dir)
 }
 
 /*
+ * Return a string with the current hostname.
+ */
+const char *get_hostname(void)
+{
+static char hostname[200] = ;
+
+if (!hostname[0]) {
+   strcpy(hostname, unknown);
+#if HAVE_GETHOSTNAME
+   gethostname(hostname, sizeof(hostname)-1);
+#endif
+   hostname[sizeof(hostname)-1] = 0;
+}
+
+return hostname;
+}
+
+/*
  * Return a string to be used to distinguish temporary files. Also tries to
  * cope with NFS by adding the local hostname.
  */
@@ -280,12 +298,7 @@ const char *tmp_string(void)
static char *ret;
 
if (!ret) {
-   char hostname[200];
-   strcpy(hostname, unknown);
-#if HAVE_GETHOSTNAME
-   gethostname(hostname, sizeof(hostname)-1);
-#endif
-   hostname[sizeof(hostname)-1] = 0;
+   const char *hostname = get_hostname();
x_asprintf(ret, %s.%u, hostname, (unsigned)getpid());
}
 
-- 
1.6.4.2

 
From d3413e81ab28bc87741dcb2240acd9977c46b69a Mon Sep 17 00:00:00 2001
From: Wilson Snyder wsny...@wsnyder.org
Date: Thu, 6 May 2010 12:43:13 -0400
Subject: [PATCH 2/2] Show times in logfiles

---
 util.c |6 +-
 1 files changed, 5 insertions(+), 1 deletions(-)

diff --git a/util.c b/util.c
index c50a7d5..ae48cf0 100644
--- a/util.c
+++ b/util.c
@@ -21,6 +21,7 @@
 
 #include sys/types.h
 #include sys/stat.h
+#include sys/time.h   // For timestamps - may not be portable
 #include fcntl.h
 #include ctype.h
 #include unistd.h
@@ -53,7 +54,10 @@ void cc_log(const char *format, ...)
if (!logfile) logfile = fopen(cache_logfile, a);
if (!logfile) return;
 
-   fprintf(logfile, [%-5d] , getpid());
+   struct timeval tv;
+   gettimeofday(tv, NULL);
+
+   fprintf(logfile, [%10d.%06d,%-5d] , (int)tv.tv_sec, (int)tv.tv_usec, 
getpid());
va_start(ap, format);
vfprintf(logfile, format, ap);
va_end(ap);
-- 
1.6.4.2

___
ccache mailing list
ccache@lists.samba.org
https://lists.samba.org/mailman/listinfo/ccache


[ccache] Corrupt objects from three colliding compiles

2010-05-06 Thread Wilson Snyder

I'm hitting a NFS issue causing bad caching.  (And yes, we have
no_subtree_check.)

This is a bug present in 2.4, but it is also present in
trunk b964c173cf493a1c0c0749a9c6a39bc07936507b which is used
for the below diagnosis.

The issue seems to occur only when there are three compiles
on different systems all compiling the same file at the same
time.  Here's the C files:

$ find . -name INV.c -exec ls -la --time-style=full-iso {} \;
-rw-rw-r-- 1 wsnyder users 405 2010-05-06 11:38:39.0 -0400 ./dir02/INV.c
-rw-rw-r-- 1 wsnyder users 405 2010-05-06 11:48:57.0 -0400 ./dir03/INV.c
-rw-rw-r-- 1 wsnyder users 405 2010-05-06 11:43:08.0 -0400 ./dir04/INV.c

They got compiled, but one got truncated

$ find . -name INV.o -exec ls -la --time-style=full-iso {} \;
-rw-rw-r-- 1 wsnyder users 916 2010-05-06 11:56:44.0 -0400 ./dir02/INV.o
-rw-rw-r-- 1 wsnyder users 916 2010-05-06 11:56:44.0 -0400 ./dir03/INV.o
-rw-rw-r-- 1 wsnyder users   0 2010-05-06 11:56:44.0 -0400 ./dir04/INV.o

Note the timestamps (unfortunately this isn't a file system
with sub-second resolution!)

The cache files:

$ ls -la --time-style=full-iso $CCACHE_DIR/2/b/2/eedf0591498af8e5f3a*
-rw-rw-r-- 1 wsnyder users 916 2010-05-06 11:56:44.0 -0400 
$CCACHE_DIR/2/b/2/eedf0591498af8e5f3a27fcc89c4f-69975.o

$ ls -la --time-style=full-iso $CCACHE_DIR/0/3/8/f19fe0a63fc088a9c57*
-rw-rw-r-- 1 wsnyder users 874 2010-05-06 11:56:44.0 -0400 
$CCACHE_DIR/0/3/8/f19fe0a63fc088a9c570845a0a4eb-584.manifest

To debug this further I added hostname and timestamps to the
log files (earlier email sent this patch), otherwise I
couldn't know what the ordering was.  This gave three
reports:

[1273161404.432174,2424 ] === 2010-05-06 11:56:44 ===
[1273161404.432636,2424 ] Hostname: maserati
[1273161404.432643,2424 ] Cwd: /nfs/compiling/dir02
[1273161404.432646,2424 ] Source file: INV.c
[1273161404.432648,2424 ] Object file: INV.o
[1273161404.432657,2424 ] Trying direct lookup
[1273161404.439730,2424 ] Looking for object file hash in 
/nfs/ccache-dir/0/3/8/f19fe0a63fc088a9c570845a0a4eb-584.manifest
[1273161404.440126,2424 ] Did not find object file hash in manifest
[1273161404.440134,2424 ] Running preprocessor
[1273161404.487509,2424 ] Got object file hash from preprocessor
[1273161404.492494,2424 ] Object file 
/nfs/ccache-dir/2/b/2/eedf0591498af8e5f3a27fcc89c4f-69975.o not in cache
[1273161404.492522,2424 ] Running real compiler
[1273161404.576412,2424 ] Stored in cache: 
/nfs/ccache-dir/2/b/2/eedf0591498af8e5f3a27fcc89c4f-69975.o
[1273161404.596098,2424 ] Created INV.o from 
/nfs/ccache-dir/2/b/2/eedf0591498af8e5f3a27fcc89c4f-69975.o
[1273161404.638443,2424 ] Added object file hash to 
/nfs/ccache-dir/0/3/8/f19fe0a63fc088a9c570845a0a4eb-584.manifest

[1273161404.469188,2084 ] === 2010-05-06 11:56:44 ===
[1273161404.469515,2084 ] Hostname: bird07
[1273161404.469519,2084 ] Cwd: /nfs/compiling/dir03
[1273161404.469521,2084 ] Source file: INV.c
[1273161404.469523,2084 ] Object file: INV.o
[1273161404.469532,2084 ] Trying direct lookup
[1273161404.471093,2084 ] Looking for object file hash in 
/nfs/ccache-dir/0/3/8/f19fe0a63fc088a9c570845a0a4eb-584.manifest
[1273161404.475427,2084 ] Did not find object file hash in manifest
[1273161404.475434,2084 ] Running preprocessor
[1273161404.523658,2084 ] Got object file hash from preprocessor
[1273161404.542730,2084 ] Created INV.o from 
/nfs/ccache-dir/2/b/2/eedf0591498af8e5f3a27fcc89c4f-69975.o
[1273161404.569955,2084 ] Added object file hash to 
/nfs/ccache-dir/0/3/8/f19fe0a63fc088a9c570845a0a4eb-584.manifest
[1273161404.570387,2084 ] Succeded getting cached result

[1273161404.511123,21936] === 2010-05-06 11:56:44 ===
[1273161404.511506,21936] Hostname: bat05
[1273161404.511510,21936] Cwd: /nfs/compiling/dir04
[1273161404.511513,21936] Source file: INV.c
[1273161404.511515,21936] Object file: INV.o
[1273161404.511523,21936] Trying direct lookup
[1273161404.514058,21936] Looking for object file hash in 
/nfs/ccache-dir/0/3/8/f19fe0a63fc088a9c570845a0a4eb-584.manifest
[1273161404.517648,21936] Did not find object file hash in manifest
[1273161404.517654,21936] Running preprocessor
[1273161404.564688,21936] Got object file hash from preprocessor
[1273161404.588776,21936] Created INV.o from 
/nfs/ccache-dir/2/b/2/eedf0591498af8e5f3a27fcc89c4f-69975.o   ***BAD OBJECT***
[1273161404.630619,21936] Added object file hash to 
/nfs/ccache-dir/0/3/8/f19fe0a63fc088a9c570845a0a4eb-584.manifest
[1273161404.634864,21936] Succeded getting cached result

The next step assumes our times are close across systems; they should be within 
about 12ms.  Here's the sorted view

[1273161404.432174,2424 ] === 2010-05-06 11:56:44 ===
[1273161404.432636,2424 ] Hostname: maserati
[1273161404.432643,2424 ] Cwd: /nfs/compiling/dir02
[1273161404.432646,2424 ] Source file: INV.c
[1273161404.432648,2424 ] Object file: INV.o
[1273161404.432657,2424 ] Trying direct lookup
[1273161404.439730,2424 ] Looking