Openwall GNU/*/Linux - a small security-enhanced Linux distro for servers
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Date: Tue, 08 Apr 2014 11:07:48 +0200
From: Frank Dittrich <frank.dittrich@...lbox.org>
To: john-dev@...ts.openwall.com
Subject: Logging issue for core john 1.8.0 with --fork=N

Solar, all,

when running core john with --fork=N, some log entries are created once
per forked process instead of just once.

$ ./john --wordlist=password.lst bcrypt.hashes --fork=3
Loaded 12 password hashes with 6 different salts (bcrypt [Blowfish 32/64
X2])
Remaining 10 password hashes with 6 different salts
Node numbers 1-3 of 3 (fork)
Press 'q' or Ctrl-C to abort, almost any other key for status
1 0g 0:00:00:02 44% 0g/s 166.3p/s 1001c/s 1669C/s hummer..iforget
Waiting for 2 children to terminate
2 0g 0:00:00:02 43% 0g/s 166.3p/s 1001c/s 1669C/s hotrod..huskies
3 0g 0:00:00:02 43% 0g/s 166.3p/s 1001c/s 1669C/s hudson..idiot
Session aborted

In the resulting john.log file, you'll find 2 different issues:

1.
Some information is printed for each process, but the first column
indicates that all log entries were created from the first process:

1 0:00:00:00 Starting a new session
1 0:00:00:00 Loaded a total of 12 password hashes with 6 different salts
1 0:00:00:00 Remaining 10 password hashes with 6 different salts
1 0:00:00:00 - Node numbers 1-3 of 3 (fork)
...
1 0:00:00:00 Starting a new session
1 0:00:00:00 Loaded a total of 12 password hashes with 6 different salts
1 0:00:00:00 Remaining 10 password hashes with 6 different salts
1 0:00:00:00 - Node numbers 1-3 of 3 (fork)
...
1 0:00:00:00 Starting a new session
1 0:00:00:00 Loaded a total of 12 password hashes with 6 different salts
1 0:00:00:00 Remaining 10 password hashes with 6 different salts
1 0:00:00:00 - Node numbers 1-3 of 3 (fork)

(With --restore, this is similar, except that you get "Continuing an
interrupted session" instead of "Starting a new session".)

2.
Some information is printed for each process, even though the
information is always the same for all individual forked processes:

1 0:00:00:00 - Hash type: bcrypt (lengths up to 72)
1 0:00:00:00 - Algorithm: Blowfish 32/64 X2
1 0:00:00:00 - Candidate passwords will be buffered and tried in chunks of 2
1 0:00:00:00 - Configured to use otherwise idle processor cycles only
...
2 0:00:00:00 - Hash type: bcrypt (lengths up to 72)
2 0:00:00:00 - Algorithm: Blowfish 32/64 X2
2 0:00:00:00 - Candidate passwords will be buffered and tried in chunks of 2
2 0:00:00:00 - Configured to use otherwise idle processor cycles only
...
3 0:00:00:00 - Hash type: bcrypt (lengths up to 72)
3 0:00:00:00 - Algorithm: Blowfish 32/64 X2
3 0:00:00:00 - Candidate passwords will be buffered and tried in chunks of 2
3 0:00:00:00 - Configured to use otherwise idle processor cycles only


The attached patch fixes both issues.
Similar changes have been committed to bleeding-jumbo.
(May be I missed something obvious here, and for MPI some information
might differ per process, e.g., the algorithm name or the "Idle" setting
in john.conf.
In that case, the second part of my patch is wrong, at least for
bleeding-jumbo.)


Now the resulting log file looks like this:

1 0:00:00:00 Starting a new session
1 0:00:00:00 Loaded a total of 12 password hashes with 6 different salts
1 0:00:00:00 Remaining 10 password hashes with 6 different salts
1 0:00:00:00 - Node numbers 1-5 of 5 (fork)
1 0:00:00:00 - Hash type: bcrypt (lengths up to 72)
1 0:00:00:00 - Algorithm: Blowfish 32/64 X2
1 0:00:00:00 - Candidate passwords will be buffered and tried in chunks of 2
1 0:00:00:00 - Configured to use otherwise idle idle processor cycles only
1 0:00:00:00 Proceeding with wordlist mode
1 0:00:00:00 - Wordlist file: password.lst
1 0:00:00:00 - No word mangling rules
4 0:00:00:00 Proceeding with wordlist mode
4 0:00:00:00 - Wordlist file: password.lst
4 0:00:00:00 - No word mangling rules
5 0:00:00:00 Proceeding with wordlist mode
5 0:00:00:00 - Wordlist file: password.lst
5 0:00:00:00 - No word mangling rules
2 0:00:00:00 Proceeding with wordlist mode
2 0:00:00:00 - Wordlist file: password.lst
2 0:00:00:00 - No word mangling rules
3 0:00:00:00 Proceeding with wordlist mode
3 0:00:00:00 - Wordlist file: password.lst
3 0:00:00:00 - No word mangling rules
1 0:00:00:00 - Will distribute words across nodes
2 0:00:00:00 - Will distribute words across nodes
3 0:00:00:00 - Will distribute words across nodes

I didn't restrict the "Proceeding with ... mode" log entry to be printed
just for john_main_process, since I was not sure whether this can differ
per process if you restore a session.


BTW:
There are also some error messages printed once per forked process.
Not sure whether or not that should be changed as well.
E.g., remove password.lst and ascii.chr, and you get

$ ./john --incremental bcrypt.hashes --fork=5
Loaded 12 password hashes with 6 different salts (bcrypt [Blowfish 32/64
X2])
Remaining 11 password hashes with 6 different salts
Node numbers 1-5 of 5 (fork)
2: fopen: ./ascii.chr: No such file or directory
1: fopen: ./ascii.chr: No such file or directory
3: fopen: ./ascii.chr: No such file or directory
$ 5: fopen: ./ascii.chr: No such file or directory
4: fopen: ./ascii.chr: No such file or directory

$ ./john --wordlist bcrypt.hashes --fork=5
Loaded 12 password hashes with 6 different salts (bcrypt [Blowfish 32/64
X2])
Remaining 11 password hashes with 6 different salts
Node numbers 1-5 of 5 (fork)
5: fopen: ./password.lst: No such file or directory
1: fopen: ./password.lst: No such file or directory
4: fopen: ./password.lst: No such file or directory
$ 2: fopen: ./password.lst: No such file or directory
3: fopen: ./password.lst: No such file or directory


Frank

diff -urpN john-1.8.0.orig/src/john.c john-1.8.0/src/john.c
--- john-1.8.0.orig/src/john.c	2013-05-29 23:27:25.000000000 +0000
+++ john-1.8.0/src/john.c	2014-04-08 08:55:01.557044952 +0000
@@ -480,8 +480,13 @@ static void john_load(void)
 		}
 
 #if OS_FORK
-		if (options.fork)
+		if (options.fork) {
+			/*
+			 * flush before forking, to avoid multple log entries
+			 */
+			log_flush();
 			john_fork();
+		}
 #endif
 	}
 }
@@ -575,10 +580,18 @@ static void john_run(void)
 			database.format->methods.reset(&database);
 			log_init(LOG_NAME, POT_NAME, options.session);
 			status_init(NULL, 1);
-			john_log_format();
-			if (idle_requested(database.format))
-				log_event("- Configured to use otherwise idle "
-					"processor cycles only");
+			if (john_main_process) {
+				john_log_format();
+				if (idle_requested(database.format))
+					log_event("- Configured to use otherwise idle "
+					          "processor cycles only");
+				/*
+				 * flush log entries to make sure they appear
+				 * before the "Proceeding with ... mode" entries
+				 * of other processes
+ 				 */
+				log_flush();
+			}
 		}
 		tty_init(options.flags & FLG_STDIN_CHK);
 

Powered by blists - more mailing lists

Your e-mail address:

Powered by Openwall GNU/*/Linux - Powered by OpenVZ