log which temporary file could not be created

When creating a temporary file, log the template. Useful for making debugging problems like file permission mistakes easier.

---
 wrapper.c |    4 ++--
 1 files changed, 2 insertions(+), 2 deletions(-)

index fd8ead3..68053cd 100644
@@ -215,7 +215,7 @@ int xmkstemp(char *template)
 
 	fd = mkstemp(template);
 	if (fd < 0)
-		die_errno("Unable to create temporary file");
+		die_errno("Unable to create temporary file '%s'", template);
 	return fd;
 }
 

@@ -225,7 +225,7 @@ int xmkstemp_mode(char *template, int mode)
 
 	fd = git_mkstemp_mode(template, mode);
 	if (fd < 0)
-		die_errno("Unable to create temporary file");
+		die_errno("Unable to create temporary file '%s'", template);
 	return fd;
 }
 

1.7.2.3

Hi,

Since mkstemp modifies its template, these hopefully would print the actual filename on errors. Examples:

fatal: Unable to create temporary file '.merge_file_Sc7R5c': File exists
fatal: Unable to create temporary file 'newrepo/.git/tOWHcxk': No space left on device

Unfortunately some mkstemp()s (such as that used to implement git_mkstemp_mode()) clear the template on error, which would result in

fatal: Unable to create temporary file '': Permission denied

What should git do in this situation?

Agreed. Thanks.

Perhaps we should also log the current working directory when the temporary filename is relative?

Perhaps we should strdup() the template before mkstemp(), and log the strdup()'ed template when the original has been cleared?

Arnout

Let's step back for a moment. Was there an example that prompted this patch? Were you aware of where git would be trying to create files in that example? (I'm genuinely curious.)

Converting the filename to an absolute path with make_absolute_path might be useful, but I am not entirely sure it is worth the complication.

Is it be preferable for the filename to always have XXXXXX in it? If so, then copying it into a temporary buffer (on-stack, preferably) could be a sane solution, yes.

Jonathan

Yes: I was trying to do an initial push to a sf.net git repo, and this gave me:

arnouten@bird:~/asdf/notion$ git push sourceforge master
[email protected]'s password: 
Counting objects: 21542, done.
Compressing objects: 100% (4179/4179), done.
fatal: Unable to create temporary file: Permission denied
error: pack-objects died of signal 13
error: pack-objects died with strange error
error: failed to push some refs to 'ssh://[email protected]/gitroot/notion/notion'
arnouten@bird:~/asdf/notion$

This seems to have been an error at the server side. I never did find out what exactly went wrong - I just re-initialized the repo using the shell access and all was fine after that.

No clue - but I'm not very into git 'internals' yet.

I'm not sure about 'always', but it'd be nice to have something to fall back to when the mkstemp clears the template.

Kind regards,

Arnout

That reminds me: the output seems more noisy than it needs to be, no?

-- 8< --
Subject: send-pack: avoid redundant "pack-objects died with strange error"

Saying "pack-objects died with strange error" after "pack-objects died of signal 13" seems kind of redundant. The latter was introduced when send-pack switched to the run-command API, which reports abnormal exits on behalf of the caller.

Normal exits with nonzero status are not reported by run-command, though. Be more helpful in reporting them by including the exit status while at it.

The result should look something like this:

	$ git push sf master
	Counting objects: 21542, done.
	Compressing objects: 100% (4179/4179), done.
	fatal: Unable to create temporary file: Permission denied
	error: pack-objects died of signal 13
	error: failed to push some refs to 'ssh://sf.net/gitroot/project/project'
	$

Or in the "controlled exit" case:

	[...]
	error: pack-objects died with status 128
	error: failed to push some refs to 'ssh://example.com/foo/bar'
	$

---
 builtin/send-pack.c |    9 +++++----
 1 files changed, 5 insertions(+), 4 deletions(-)

index 481602d..51b722b 100644
@@ -50,7 +50,7 @@ static int pack_objects(int fd, struct ref *refs, struct extra_have_objects *ext
 		NULL,
 	};
 	struct child_process po;
-	int i;
+	int i, status;
 
 	i = 4;
 	if (args->use_thin_pack)

@@ -100,9 +100,10 @@ static int pack_objects(int fd, struct ref *refs, struct extra_have_objects *ext
 		po.out = -1;
 	}
 
-	if (finish_command(&po))
-		return error("pack-objects died with strange error");
-	return 0;
+	status = finish_command(&po);
+	if (status > 0)
+		error("pack-objects died with status %d", status);
+	return status;
 }
 
 static int receive_status(int in, struct ref *refs)

1.7.2.3

Saying "pack-objects died with strange error" after "pack-objects died of signal 13" seems kind of redundant. The latter was introduced when send-pack switched to the run-command API, which reports abnormal exits on behalf of the caller.

Normal exits with nonzero status are not reported by run-command, though. Be more helpful in reporting them by including the exit status while at it (and be sure to continue to return a value less than zero from pack_objects() for that case).

The result should look something like this:

	$ git push sf master
	Counting objects: 21542, done.
	Compressing objects: 100% (4179/4179), done.
	fatal: Unable to create temporary file: Permission denied
	error: pack-objects died of signal 13
	error: failed to push some refs to 'ssh://sf.net/gitroot/project/project'
	$

Or in the "controlled exit" case:

	[...]
	error: pack-objects died with status 128
	error: failed to push some refs to 'ssh://example.com/foo/bar'
	$

---

	if (pack_objects(...) < 0)

	status = finish_command(&po);
	if (status > 0)
 -		error("pack-objects died with status %d", status);
 +		return error("pack-objects died with status %d", status);
	return status;

 builtin/send-pack.c |    9 +++++----
 1 files changed, 5 insertions(+), 4 deletions(-)

index 481602d..8854748 100644
@@ -50,7 +50,7 @@ static int pack_objects(int fd, struct ref *refs, struct extra_have_objects *ext
 		NULL,
 	};
 	struct child_process po;
-	int i;
+	int i, status;
 
 	i = 4;
 	if (args->use_thin_pack)

@@ -100,9 +100,10 @@ static int pack_objects(int fd, struct ref *refs, struct extra_have_objects *ext
 		po.out = -1;
 	}
 
-	if (finish_command(&po))
-		return error("pack-objects died with strange error");
-	return 0;
+	status = finish_command(&po);
+	if (status > 0)
+		return error("pack-objects died with status %d", status);
+	return status;
 }
 
 static int receive_status(int in, struct ref *refs)

1.7.2.3

The rationale for this is the assumption that before a program or script exits with non-zero status, it will have reported an error.

I sense that this quote is not complete. Did you strip some error message by writing just "[...]"?

	if (finish_command(&po))
		return -1;

Saying "pack-objects died with strange error" after "pack-objects died of signal 13" seems kind of redundant. The latter message was introduced when the run-command API changed to report abnormal exits on behalf of the caller (v1.6.5-rc0~86^2~5, 2009-07-04).

Similarly, after a controlled pack-objects failure (detectable as a normal exit with nonzero status), a "died with strange error" message would be redundant next to the message from pack-objects itself.

So leave off the "strange error" messages.

The result should look something like this:

	$ git push sf master
	Counting objects: 21542, done.
	Compressing objects: 100% (4179/4179), done.
	fatal: Unable to create temporary file: Permission denied
	error: pack-objects died of signal 13
	error: failed to push some refs to 'ssh://sf.net/gitroot/project/project'
	$

Or in the "controlled exit" case (contrived example):

	[...]
	fatal: delta size changed
	error: failed to push some refs to 'ssh://example.com/foo/bar'
	$

---

That was invented example output.

Googling for "pack-objects died with strange error" gives me [1], with v1.6.2:

	$ git push
	Counting objects: 68, done.
	Delta compression using 2 threads.
	Compressing objects: 100% (50/50), done.
	Connection to SERVER closed by remote host.
	error: pack-objects died with strange error
	error: failed to push some refs to 'SERVER:PROJECT.git'

and [2], with v1.6.4.4:

Counting objects: 4364, done.
Delta compression using up to 2 threads. Compressing objects: 100% (4240/4240), done.
error: pack-objects died with strange error | 44 KiB/s
error: failed to push some refs to 'mysite:main_site_repo'

and some similar examples. All involve git versions before v1.6.5-rc0~86^2~5 (run_command: report system call errors instead of returning error codes, 2009-07-04) and after a triage turn out to be signals.

Let's go with your fix (thanks!).

[1] http://stackoverflow.com/questions/718962/git-push-error-pack-objects-died-with-strange-error
[2] http://stackoverflow.com/questions/1781013/git-error-failed-to-push-some-refs-pack-objects-died-with-strange-error

 builtin/send-pack.c |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

index 481602d..8aa3031 100644
@@ -101,7 +101,7 @@ static int pack_objects(int fd, struct ref *refs, struct extra_have_objects *ext
 	}
 
 	if (finish_command(&po))
-		return error("pack-objects died with strange error");
+		return -1;
 	return 0;
 }
 

1.7.2.3

For that matter, I am not sure if it is worth the strdup "just in case it fails" either.

I think it's valuable to give better error messages. A strdup/strncpy does not take much resources (especially compared to creating the temporary file), and makes the code only slightly less readable as the change is fairly local.

Below is an updated patch that:
- copies the original template to the stack to be able to log it in case mkstemp clears it
- on failure, logs the modified template, if any, or the original one
- logs the CWD when the template is relative
- adds a test testing this gives sane output (and doesn't crash, etc)

---
 Makefile          |    1 +
 t/t0007-mktemp.sh |   16 ++++++++++++++++
 test-mktemp.c     |   25 +++++++++++++++++++++++++
 wrapper.c         |   30 ++++++++++++++++++++++++++----
 4 files changed, 68 insertions(+), 4 deletions(-)
 create mode 100755 t/t0007-mktemp.sh
 create mode 100644 test-mktemp.c

index 1f1ce04..30aafa2 100644
@@ -428,6 +428,7 @@ TEST_PROGRAMS_NEED_X += test-string-pool
 TEST_PROGRAMS_NEED_X += test-svn-fe
 TEST_PROGRAMS_NEED_X += test-treap
 TEST_PROGRAMS_NEED_X += test-index-version
+TEST_PROGRAMS_NEED_X += test-mktemp
 
 TEST_PROGRAMS = $(patsubst %,%$X,$(TEST_PROGRAMS_NEED_X))
 

new file mode 100755
index 0000000..7abeeca
@@ -0,0 +1,16 @@
+#!/bin/sh
+
+test_description='test creating temporary files'
+. ./test-lib.sh
+
+check_errormsg() {
+	test_expect_success "$1" "
+		test-mktemp $2 &>actual
+		grep \"$3\" actual
+		"
+}
+
+check_errormsg "Creating temporary file in nonexisting directory" n "Unable to create temporary file '/tmp/does/not/exist/test"
+check_errormsg "Creating temporary file in invalid relative directory" p "at /"
+
+test_done

new file mode 100644
index 0000000..fad2908
@@ -0,0 +1,25 @@
+/*
+ * test-mktemp.c: code to exercise the creation of temporary files
+ */
+#include "wrapper.h"
+
+int main(int argc, char *argv[])
+{
+	if (argc != 2) {
+		fprintf(stderr, "Expected 1 parameter defining the situation to test");
+		exit(-1);
+	}
+	switch (argv[1][0]) {
+		case 'n':
+			// temporary file in nonexistent directory
+			xmkstemp(strdup("/tmp/does/not/exist/testXXXXXX"));
+			break;
+		case 'p':
+			// temporary file in directory where we have no write permissions
+			xmkstemp(strdup("../../foo/testXXXXXX"));
+			break;
+		default:
+			fprintf(stderr, "No such test case: %s\n", argv[0]);
+	}
+	return 0;
+}

index fd8ead3..b588e67 100644
@@ -212,20 +212,42 @@ FILE *xfdopen(int fd, const char *mode)
 int xmkstemp(char *template)
 {
 	int fd;
+	char originalTemplate[255];
+	strncpy(originalTemplate, template, 255);
+	originalTemplate[254] = '\0';
 
 	fd = mkstemp(template);
-	if (fd < 0)
-		die_errno("Unable to create temporary file");
+	if (fd < 0) {
+		if (strlen(template) == 0) {
+			template = originalTemplate;
+		}
+		if (*template == '/') {
+			die_errno("Unable to create temporary file '%s'", template);
+		} else {
+			die_errno("Unable to create temporary file '%s' at %s", template, getcwd(NULL, 0));
+		}
+	}
 	return fd;
 }
 
 int xmkstemp_mode(char *template, int mode)
 {
 	int fd;
+	char originalTemplate[255];
+	strncpy(originalTemplate, template, 255);
+	originalTemplate[254] = '\0';
 
 	fd = git_mkstemp_mode(template, mode);
-	if (fd < 0)
-		die_errno("Unable to create temporary file");
+	if (fd < 0) {
+		if (strlen(template) == 0) {
+			template = originalTemplate;
+		}
+		if (*template == '/') {
+			die_errno("Unable to create temporary file '%s'", template);
+		} else {
+			die_errno("Unable to create temporary file '%s' at %s", template, getcwd(NULL, 0));
+		}
+	}
 	return fd;
 }
 

1.7.2.3

Thanks for your feedback.

Modified patch all the way below ;)

:)

I think it is, but 'usage' is indeed neater. Done.

Changed to /* */

Done

Changed to '2>', tested with zsh, ksh and bash.

Done and moved

Changed to 'origtemplate'

Jep, thanks, didn't know that one. Changed.

I thought strlen() would be a bit neater/more readable - but changed.

Changed

Changed.

Verified the testcases still succeed.

The patch below:
- copies the original template to the stack, to be able to log it in case mkstemp clears it
- on failure, logs the modified template, if any, or the original one
- logs the CWD when the template is relative
- adds a test testing this gives sane output (and doesn't crash, etc)

---
 Makefile               |    1 +
 t/t0070-fundamental.sh |   13 +++++++++++++
 test-mktemp.c          |   14 ++++++++++++++
 wrapper.c              |   26 ++++++++++++++++++++++----
 4 files changed, 50 insertions(+), 4 deletions(-)
 create mode 100644 test-mktemp.c

index 1f1ce04..30aafa2 100644
@@ -428,6 +428,7 @@ TEST_PROGRAMS_NEED_X += test-string-pool
 TEST_PROGRAMS_NEED_X += test-svn-fe
 TEST_PROGRAMS_NEED_X += test-treap
 TEST_PROGRAMS_NEED_X += test-index-version
+TEST_PROGRAMS_NEED_X += test-mktemp
 
 TEST_PROGRAMS = $(patsubst %,%$X,$(TEST_PROGRAMS_NEED_X))
 

index 680d7d6..9bee8bf 100755
@@ -12,4 +12,17 @@ test_expect_success 'character classes (isspace, isalpha etc.)' '
 	test-ctype
 '
 
+test_expect_success 'mktemp to nonexistent directory prints filename' '
+	test_must_fail test-mktemp doesnotexist/testXXXXXX 2>err &&
+	grep "doesnotexist/test" err
+'
+
+test_expect_success POSIXPERM 'mktemp to unwritable directory prints filename' '
+	mkdir cannotwrite &&
+	chmod -w cannotwrite &&
+	test_when_finished "chmod +w cannotwrite" &&
+	test_must_fail test-mktemp cannotwrite/testXXXXXX 2>err &&
+	grep "cannotwrite/test" err
+'
+
 test_done

new file mode 100644
index 0000000..30e266a
@@ -0,0 +1,14 @@
+/*
+ * test-mktemp.c: code to exercise the creation of temporary files
+ */
+#include "wrapper.h"
+
+int main(int argc, char *argv[])
+{
+	if (argc != 2) {
+		usage("Expected 1 parameter defining the temporary file template");
+	}
+	xmkstemp(strdup(argv[1]));
+
+	return 0;
+}

index fd8ead3..b5f10d1 100644
@@ -212,20 +212,38 @@ FILE *xfdopen(int fd, const char *mode)
 int xmkstemp(char *template)
 {
 	int fd;
+	char origtemplate[255];
+	strlcpy(origtemplate, template, 255);
 
 	fd = mkstemp(template);
-	if (fd < 0)
-		die_errno("Unable to create temporary file");
+	if (fd < 0) {
+		if (!template[0])
+			template = origtemplate;
+
+		if (is_absolute_path(template))
+			die_errno("Unable to create temporary file '%s'", template);
+		else
+			die_errno("Unable to create temporary file '%s' at %s", template, getcwd(NULL, 0));
+	}
 	return fd;
 }
 
 int xmkstemp_mode(char *template, int mode)
 {
 	int fd;
+	char origtemplate[255];
+	strlcpy(origtemplate, template, 255);
 
 	fd = git_mkstemp_mode(template, mode);
-	if (fd < 0)
-		die_errno("Unable to create temporary file");
+	if (fd < 0) {
+		if (!template[0])
+			template = origtemplate;
+
+		if (is_absolute_path(template))
+			die_errno("Unable to create temporary file '%s'", template);
+		else
+			die_errno("Unable to create temporary file '%s' at %s", template, getcwd(NULL, 0));
+	}
 	return fd;
 }
 

1.7.2.3