Logging tweaks

Add some function-like macros for log/warn/both

WARN_AND_LOG() is like fprintf_color() then log_event(), with same message.

WARN_ONCE() is like fprintf_color() but only once per session.
LOG_ONCE() is like log_event() but only once per session.
WARN_AND_LOG_ONCE() does both, with same message.

Also add error color to error(), pexit() and similar stuff in misc.c

Author: magnumripper

run/john.conf

@@ -113,7 +113,7 @@ TerminalReset = ^[0m
 # which define red for errors, green for notices and yellow for warnings).
 # Note that you don't strictly need to use ANSI sequences - other things are
 # fine too.
-# Set this to N or comment it out to disable all color stuff.
+# Set this to N to disable all color stuff.
 UseColors = Y
 ColorError = ^[0;31m
 ColorNotice = ^[0;32m

src/7z_common_plug.c

@@ -101,9 +101,6 @@ struct fmt_tests sevenzip_tests[] = {
 
 sevenzip_salt_t *sevenzip_salt;
 
-#define YEL	"\x1b[0;33m"
-#define NRM	"\x1b[0m"
-
 int sevenzip_trust_padding;
 
 static char *comp_type[16] = { "stored", "LZMA1", "LZMA2", "PPMD", NULL, NULL, "BZIP2", "DEFLATE" };
@@ -140,23 +137,23 @@ int sevenzip_valid(char *ciphertext, struct fmt_main *self)
 			    && type != 128) {
 		if (john_main_process && !warned[type]) {
 			warned[type] = 1;
-			fprintf(stderr, YEL "Warning: Not loading files with unsupported compression type %s (0x%02x)\n" NRM,
+			fprintf_color(color_warning, stderr, "Warning: Not loading files with unsupported compression type %s (0x%02x)\n",
 			        comp_type[c_type] ? comp_type[c_type] : "(unknown)", type);
 #if !HAVE_LIBBZ2
 			if (type == 6)
-				fprintf(stderr, YEL "Rebuild with libbz2 to get support for that type.\n" NRM);
+				fprintf_color(color_warning, stderr, "Rebuild with libbz2 to get support for that type.\n");
 #endif
 #if !HAVE_LIBZ
 			if (type == 7)
-				fprintf(stderr, YEL "Rebuild with libz (zlib) to get support for that type.\n" NRM);
+				fprintf_color(color_warning, stderr, "Rebuild with libz (zlib) to get support for that type.\n");
 #endif
 		}
 		goto err;
 	}
 	if (john_main_process && !ldr_in_pot && !self_test_running &&
 	    options.verbosity > VERB_DEFAULT && !warned[type]) {
 		warned[type] = 1;
-		fprintf(stderr, YEL "Saw file(s) with compression type %s%s%s (0x%02x)\n" NRM,
+		fprintf_color(color_notice, stderr, "Saw file(s) with compression type %s%s%s (0x%02x)\n",
 		        precomp_type[p_type], p_type ? "+" : "", comp_type[c_type], type);
 	}
 	if ((p = strtokm(NULL, "$")) == NULL) /* NumCyclesPower */
@@ -174,11 +171,8 @@ int sevenzip_valid(char *ciphertext, struct fmt_main *self)
 		goto err;
 	len = atoi(p);
 	if (len > 0 && strstr(self->params.label, "-opencl")) {
-		static int warned;
-
-		if (!warned++)
-			fprintf(stderr, YEL "%s: Warning: Not loading hashes with salt due to optimizations. Please report!\n" NRM,
-			        self->params.label);
+		if (!ldr_in_pot && john_main_process)
+			WARN_ONCE(color_warning, stderr, "%s: Warning: Not loading hashes with salt due to optimizations. Please report!\n", self->params.label);
 		goto err;
 	}
 	if (len > 16)
@@ -355,7 +349,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 
 #if DEBUG
 	if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-		fprintf(stderr, "\nType %02x (%s%s%s) AES length %zu, packed len %zu, pad size %d, crc len %zu\n",
+		fprintf_color(color_notice, stderr, "\nType %02x (%s%s%s) AES length %zu, packed len %zu, pad size %d, crc len %zu\n",
 		        sevenzip_salt->type, precomp_type[p_type] ? precomp_type[p_type] : "",
 		        p_type ? "+" : "",
 		        comp_type[c_type] ? comp_type[c_type] : "(unknown)",
@@ -379,12 +373,11 @@ int sevenzip_decrypt(unsigned char *derived_key)
 			if (buf[i] != 0) {
 #if DEBUG
 				if (!benchmark_running && options.verbosity >= VERB_DEBUG) {
-					fprintf(stderr, YEL "Early padding check failed, ");
+					fprintf_color(color_warning, stderr, "Early padding check failed, ");
 					dump_stderr_msg("padding", buf + 16 - pad_size, pad_size);
-					fprintf(stderr, NRM);
 				}
 				if (sevenzip_salt->type == 0x80)
-					fprintf(stderr, YEL "We don't have data for complete decryption\n");
+					WARN_ONCE(color_warning, stderr, "We don't have data for complete decryption\n");
 				break;
 #else
 				return 0;
@@ -395,13 +388,13 @@ int sevenzip_decrypt(unsigned char *derived_key)
 		}
 #if DEBUG
 		if (!nbytes && !benchmark_running && options.verbosity >= VERB_DEBUG)
-			fprintf(stderr, "Early padding check passed\n");
+			fprintf_color(color_notice, stderr, "Early padding check passed\n");
 		else
 			nbytes = 0;
-#else
+		if (self_test_running)
+#endif
 		if (sevenzip_salt->type == 0x80) /* We only have truncated data */
 			return 1;
-#endif
 	}
 
 	/* Complete decryption */
@@ -417,9 +410,8 @@ int sevenzip_decrypt(unsigned char *derived_key)
 			if (out[i] != 0) {
 #if DEBUG
 				if (!benchmark_running && options.verbosity >= VERB_DEBUG) {
-					fprintf(stderr, YEL "Full data padding check failed, ");
+					fprintf_color(color_warning, stderr, "Full data padding check failed, ");
 					dump_stderr_msg("padding", out + sevenzip_salt->aes_length - pad_size, pad_size);
-					fprintf(stderr, NRM);
 				}
 				break;
 #else
@@ -431,7 +423,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 		}
 #if DEBUG
 		if (!nbytes && !benchmark_running && options.verbosity >= VERB_DEBUG)
-			fprintf(stderr, "Padding check passed\n");
+			fprintf_color(color_notice, stderr, "Padding check passed\n");
 #endif
 	}
 
@@ -456,7 +448,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 		    out_size == crc_len) {
 #if DEBUG
 			if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-				fprintf(stderr, "LZMA decoding passed, %zu/%zu -> %zu/%zu, props %02x%02x%02x%02x\n",
+				fprintf_color(color_notice, stderr, "LZMA decoding passed, %zu/%zu -> %zu/%zu, props %02x%02x%02x%02x\n",
 				        in_size, sevenzip_salt->packed_size, out_size, crc_len, sevenzip_salt->decoder_props[0],
 				        sevenzip_salt->decoder_props[1], sevenzip_salt->decoder_props[2], sevenzip_salt->decoder_props[3]);
 #endif
@@ -465,7 +457,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 		} else {
 #if DEBUG
 			if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-				fprintf(stderr, YEL "LZMA decoding failed, %zu/%zu -> %zu/%zu, props %02x%02x%02x%02x\n" NRM,
+				fprintf_color(color_warning, stderr, "LZMA decoding failed, %zu/%zu -> %zu/%zu, props %02x%02x%02x%02x\n",
 				        in_size, sevenzip_salt->packed_size, out_size, crc_len, sevenzip_salt->decoder_props[0],
 				        sevenzip_salt->decoder_props[1], sevenzip_salt->decoder_props[2], sevenzip_salt->decoder_props[3]);
 #endif
@@ -488,15 +480,15 @@ int sevenzip_decrypt(unsigned char *derived_key)
 		    out_size == crc_len) {
 #if DEBUG
 			if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-				fprintf(stderr, "LZMA2 decoding passed, %zu/%zu -> %zu/%zu, props %02x\n",
+				fprintf_color(color_notice, stderr, "LZMA2 decoding passed, %zu/%zu -> %zu/%zu, props %02x\n",
 				        in_size, sevenzip_salt->packed_size, out_size, crc_len, sevenzip_salt->decoder_props[0]);
 #endif
 			MEM_FREE(out);
 			out = new_out;
 		} else {
 #if DEBUG
 			if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-				fprintf(stderr, YEL "LZMA2 decoding failed, %zu/%zu -> %zu/%zu, props %02x\n" NRM,
+				fprintf_color(color_warning, stderr, "LZMA2 decoding failed, %zu/%zu -> %zu/%zu, props %02x\n",
 				        in_size, sevenzip_salt->packed_size, out_size, crc_len, sevenzip_salt->decoder_props[0]);
 #endif
 			MEM_FREE(new_out);
@@ -526,7 +518,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 		if (ret == BZ_STREAM_END) {
 #if DEBUG
 			if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-				fprintf(stderr, "BZIP2 decoding passed, %zu/%zu -> %zu/%zu\n",
+				fprintf_color(color_notice, stderr, "BZIP2 decoding passed, %zu/%zu -> %zu/%zu\n",
 				        sevenzip_salt->packed_size - inf_stream.avail_in, sevenzip_salt->packed_size,
 				        crc_len - inf_stream.avail_out, crc_len);
 #endif
@@ -535,7 +527,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 		} else {
 #if DEBUG
 			if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-				fprintf(stderr, YEL "BZIP2 decoding failed, %zu/%zu -> %zu/%zu\n" NRM,
+				fprintf_color(color_warning, stderr, "BZIP2 decoding failed, %zu/%zu -> %zu/%zu\n",
 				        sevenzip_salt->packed_size - inf_stream.avail_in, sevenzip_salt->packed_size,
 				        crc_len - inf_stream.avail_out, crc_len);
 #endif
@@ -564,7 +556,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 		if (ret == Z_STREAM_END) {
 #if DEBUG
 			if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-				fprintf(stderr, "DEFLATE decoding passed, %zu/%zu -> %zu/%zu\n",
+				fprintf_color(color_notice, stderr, "DEFLATE decoding passed, %zu/%zu -> %zu/%zu\n",
 				        sevenzip_salt->packed_size - inf_stream.avail_in, sevenzip_salt->packed_size,
 				        crc_len - inf_stream.avail_out, crc_len);
 #endif
@@ -573,7 +565,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 		} else {
 #if DEBUG
 			if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-				fprintf(stderr, YEL "DEFLATE decoding failed, %zu/%zu -> %zu/%zu\n" NRM,
+				fprintf_color(color_warning, stderr, "DEFLATE decoding failed, %zu/%zu -> %zu/%zu\n",
 				        sevenzip_salt->packed_size - inf_stream.avail_in, sevenzip_salt->packed_size,
 				        crc_len - inf_stream.avail_out, crc_len);
 #endif
@@ -586,7 +578,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 	if (p_type) {
 #if DEBUG
 		if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-			fprintf(stderr, "Decoding %s, props %02x\n", precomp_type[p_type], sevenzip_salt->preproc_props);
+			fprintf_color(color_notice, stderr, "Decoding %s, props %02x\n", precomp_type[p_type], sevenzip_salt->preproc_props);
 #endif
 		if (p_type == 1) {
 			uint32_t state;
@@ -595,12 +587,8 @@ int sevenzip_decrypt(unsigned char *derived_key)
 			x86_Convert(out, crc_len, 0, &state, 0);
 		}
 		else if (p_type == 2) {
-			if (!benchmark_running && options.verbosity >= VERB_DEFAULT) {
-				static int warned;
-
-				if (!warned++)
-					fprintf(stderr, YEL "Can't decode BCJ2, so skipping CRC check" NRM);
-			}
+			if (!benchmark_running && options.verbosity >= VERB_DEFAULT)
+				WARN_ONCE(color_warning, stderr, "Can't decode BCJ2, so skipping CRC check");
 			goto exit_good;
 		}
 		else if (p_type == 3)
@@ -620,7 +608,7 @@ int sevenzip_decrypt(unsigned char *derived_key)
 			Delta_Decode(state, sevenzip_salt->preproc_props + 1, out, crc_len);
 #if DEBUG
 			if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-				fprintf(stderr, YEL "DELTA decoding can't fail so result unknown\n" NRM);
+				fprintf_color(color_notice, stderr, "DELTA decoding can't fail so result unknown\n");
 #endif
 		}
 	}
@@ -636,13 +624,13 @@ int sevenzip_decrypt(unsigned char *derived_key)
 	if (ccrc == sevenzip_salt->crc) {
 #if DEBUG
 		if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-			fprintf(stderr, "CRC check passed (%08x)\n", ccrc);
+			fprintf_color(color_notice, stderr, "CRC check passed (%08x)\n", ccrc);
 #endif
 		goto exit_good;
 	}
 #if DEBUG
 	if (!benchmark_running && options.verbosity >= VERB_DEBUG)
-		fprintf(stderr, YEL "CRC failed, %08x vs %08x\n" NRM, ccrc, sevenzip_salt->crc);
+		fprintf_color(color_warning, stderr, "CRC failed, %08x vs %08x\n", ccrc, sevenzip_salt->crc);
 #endif
 
 exit_bad:

src/bestcrypt_ve_fmt_plug.c

@@ -31,6 +31,7 @@ john_register_one(&fmt_bestcrypt_ve);
 #endif
 
 #include "arch.h"
+#include "john.h"
 #include "misc.h"
 #include "common.h"
 #include "formats.h"
@@ -229,7 +230,8 @@ static int valid(char *ciphertext, struct fmt_main *self)
 	if (atoi(p) != 8 && atoi(p) != 9 && atoi(p) != 10 && atoi(p) != 11 && atoi(p) != 15)
 		goto err;
 	if (atoi(p) == 11) {
-		fprintf(stderr, "Warning: " FORMAT_LABEL ": RC6 encryption not supported yet!\n");
+		if (john_main_process && !ldr_in_pot)
+			fprintf_color(color_warning, stderr, "Warning: " FORMAT_LABEL ": RC6 encryption not supported yet!\n");
 		goto err;
 	}
 	if ((p = strtokm(NULL, "$")) == NULL) // salt

src/bitshares_fmt_plug.c

@@ -300,8 +300,9 @@ static int crypt_all(int *pcount, struct db_salt *salt)
 						any_cracked |= 1;
 
 						if (memcmp(km, out_full, 4) != 0) {
-							fprintf(stderr, "Warning: " FORMAT_LABEL ": Good padding, but bad checksum"
-							    " (corrupted data or false positive?) - will keep guessing\n");
+							fprintf_color(color_warning, stderr,
+							              "Warning: " FORMAT_LABEL ": Good padding, but bad checksum"
+							              " (corrupted data or false positive?) - will keep guessing\n");
 							fmt_bitshares.params.flags |= FMT_NOT_EXACT;
 						}
 					}

src/c3_fmt.c

@@ -371,11 +371,12 @@ static int valid(char *ciphertext, struct fmt_main *self)
 
 	if (id != 10 && !ldr_in_pot)
 	if (john_main_process)
-		fprintf(stderr, "Warning: "
-		    "hash encoding string length %d, type id %c%c\n"
-		    "appears to be unsupported on this system; "
-		    "will not load such hashes.\n",
-		    length, id > 0x20 ? '$' : '#', id > 0x20 ? id : '0' + id);
+		fprintf_color(color_warning, stderr,
+		              "Warning: "
+		              "hash encoding string length %d, type id %c%c\n"
+		              "appears to be unsupported on this system; "
+		              "will not load such hashes.\n",
+		              length, id > 0x20 ? '$' : '#', id > 0x20 ? id : '0' + id);
 
 	if (!sup_length[length])
 		sup_length[length] = -1;

src/color.c

@@ -9,6 +9,7 @@
 #include "config.h"
 #include "options.h"
 
+const char* const color_none = "";
 char *color_error, *color_notice, *color_warning, *color_end;
 
 /*
@@ -34,11 +35,11 @@ char *parse_esc(const char *string)
 
 void color_init()
 {
-	if (cfg_get_bool(SECTION_OPTIONS, NULL, "UseColors", 0)) {
+	if (cfg_get_bool(SECTION_OPTIONS, NULL, "UseColors", 1)) {
 		color_error = parse_esc(cfg_get_param(SECTION_OPTIONS, NULL, "ColorError"));
 		color_notice = parse_esc(cfg_get_param(SECTION_OPTIONS, NULL, "ColorNotice"));
 		color_warning = parse_esc(cfg_get_param(SECTION_OPTIONS, NULL, "ColorWarning"));
 		color_end = parse_esc(cfg_get_param(SECTION_OPTIONS, NULL, "ColorEnd"));
 	} else
-		color_error = color_notice = color_warning = color_end = "";
+		color_error = color_notice = color_warning = color_end = (char*)color_none;
 }

src/color.h

@@ -8,11 +8,8 @@
 #ifndef _JOHN_COLOR_H
 #define _JOHN_COLOR_H
 
-extern char *parse_esc(const char *string);
-extern void color_init();
-
-/* Color escape sequences as strings */
-extern char *color_error, *color_notice, *color_warning, *color_end;
+#include <stdio.h>
+#include <unistd.h> /* isatty */
 
 #define printf_color(color, ...)	fprintf_color(color, stdout, __VA_ARGS__);
 
@@ -40,4 +37,11 @@ extern char *color_error, *color_notice, *color_warning, *color_end;
 			fputs(color_end, handle); \
 	} while (0)
 
+extern char *parse_esc(const char *string);
+extern void color_init();
+
+/* Color escape sequences as strings */
+extern const char* const color_none;
+extern char *color_error, *color_notice, *color_warning, *color_end;
+
 #endif	/* _JOHN_COLOR_H */

src/john.c

@@ -2093,6 +2093,12 @@ int main(int argc, char **argv)
 		return base64conv(argc, argv);
 	}
 
+	/*
+	 * For having these as empty strings in case a color warning/error is
+	 * printed before we init colors.
+	 */
+	color_error = color_notice = color_warning = color_end = (char*)color_none;
+
 #if !(CPU_FALLBACK || OMP_FALLBACK || defined(CPU_FALLBACK_BINARY) || defined(OMP_FALLBACK_BINARY))
 	path_init(argv);
 #endif