Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Random format errors reprocessing the .POT files in TS with -passthru=--fork=n" #1074

Closed
frank-dittrich opened this issue Mar 4, 2015 · 9 comments

Comments

@frank-dittrich
Copy link
Collaborator

On my laptop (quad core with HT) I need a sufficiently high number of forked processes to trigger this.
On another quad core system without HT, I was able to trigger this with -passthru="--fork=2", but a higher number of forked processes helps to make such errors more likely (increase the number of errors from 1 or 2 with --fork=2 to about 15-30 for --fork=20).

(master)test $ ./jtrts.pl -type dynamic -q -passthru="--fork=32"
-------------------------------------------------------------------------------
- JtR-TestSuite (jtrts). Version 1.13, Dec 21, 2014.  By, Jim Fougeron & others
- Testing:  John the Ripper password cracker, version 1.8.0.2-jumbo-1-bleeding_omp_memdbg_asan [linux-gnu 64-bit AVX-autoconf]
--------------------------------------------------------------------------------
.pot CHK:dynamic_0                guesses:  920 -show= 920 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (920 val-pwd  1 inval-pwd)
.pot CHK:dynamic_9                guesses: 1237 -show=1237 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1237 val-pwd  1 inval-pwd)
.pot CHK:dynamic_16               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1500 val-pwd  1 inval-pwd)
.pot CHK:dynamic_18               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1500 val-pwd  1 inval-pwd)
.pot CHK:dynamic_20               guesses: 1293 -show=1293 0:00:00:00 DONE : Expected count(s) (1293)  [!!!FAILED4!!!]  (1293 val-pwd  1 inval-pwd)
.pot CHK:dynamic_31               guesses:  916 -show= 916 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (916 val-pwd  1 inval-pwd)
.pot CHK:dynamic_38               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1500 val-pwd  1 inval-pwd)
.pot CHK:dynamic_61               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1500 val-pwd  1 inval-pwd)
.pot CHK:formspring               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1500 val-pwd  1 inval-pwd)
.pot CHK:dynamic_1011             guesses: 1197 -show=1235 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1235 val-pwd  1 inval-pwd)
.pot CHK:dynamic_1012             guesses: 1235 -show=1235 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1235 val-pwd  1 inval-pwd)
.pot CHK:dynamic_1031             guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1500 val-pwd  2 inval-pwd)
.pot CHK:dynamic_1300             guesses:  920 -show= 920 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (920 val-pwd  1 inval-pwd)
.pot CHK:dynamic_2001             guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1500 val-pwd  1 inval-pwd)
.pot CHK:dynamic_2006             guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1500 val-pwd  2 inval-pwd)
.pot CHK:PHPass                   guesses:  970 -show= 970 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (970 val-pwd  1 inval-pwd)
.pot CHK:mediawiki                guesses: 1237 -show=1237 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1237 val-pwd  1 inval-pwd)
Some tests had Errors. Performed 230 tests.  17 errors reprocessing the .POT files      
Time used was 917 seconds

The error is not related to memdbg or asan, since I was able to reproduce this with asan and memdbg disabled.
Which of these formats fail appears to be random, since for releated runs the result differs.
But it looks like only dynamic and thin formats fail in this way.

@frank-dittrich
Copy link
Collaborator Author

May be it is not related to dynamic, because just now I triggered the same problem for sha512crypt-new.

@frank-dittrich frank-dittrich changed the title Random dynamic format errors reprocessing the .POT files in TS with -passthru=--fork=n" Random format errors reprocessing the .POT files in TS with -passthru=--fork=n" Mar 4, 2015
@frank-dittrich
Copy link
Collaborator Author

Could be an older problem (related to locking?) which is not yet fully fixed.
For 1.8.0-jumbo-1, I get:

(master)test $ ./jtrts.pl -type dynamic -q -passthru="--fork=32"
-------------------------------------------------------------------------------
- JtR-TestSuite (jtrts). Version 1.13, Dec 21, 2014.  By, Jim Fougeron & others
- Testing:  John the Ripper password cracker, version 1.8.0-jumbo-1_omp [linux-gnu 64-bit AVX-autoconf]
--------------------------------------------------------------------------------
.pot CHK:dynamic_1                guesses:  923 -show= 923 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (923 val-pwd  1 inval-pwd)
.pot CHK:dynamic_4                guesses:  916 -show= 916 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (916 val-pwd  1 inval-pwd)
form=dynamic_12                   guesses: 1496 -show=1496 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_12               guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1445 val-pwd  36 inval-pwd)
form=dynamic_13                   guesses: 1496 -show=1496 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_13               guesses: 1488 -show=1488 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1438 val-pwd  38 inval-pwd)
form=dynamic_15                   guesses: 1476 -show=1476 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_15               guesses: 1471 -show=1471 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1424 val-pwd  35 inval-pwd)
form=dynamic_16                   guesses: 1445 -show=1445 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_16               guesses: 1434 -show=1434 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1394 val-pwd  30 inval-pwd)
.pot CHK:dynamic_17               guesses:  970 -show= 970 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (970 val-pwd  1 inval-pwd)
form=dynamic_18                   guesses:  673 -show= 673 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_18               guesses:  673 -show= 673 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (673 val-pwd  1 inval-pwd)
form=dynamic_24                   guesses: 1492 -show=1492 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_24               guesses: 1484 -show=1484 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1484 val-pwd  0 inval-pwd)
form=dynamic_25                   guesses: 1492 -show=1492 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_25               guesses: 1483 -show=1483 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1483 val-pwd  0 inval-pwd)
form=dynamic_26                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_26               guesses: 1488 -show=1488 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1438 val-pwd  34 inval-pwd)
form=dynamic_35                   guesses: 1488 -show=1488 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_35               guesses: 1484 -show=1484 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1484 val-pwd  0 inval-pwd)
form=dynamic_36                   guesses: 1489 -show=1489 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_36               guesses: 1486 -show=1486 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1486 val-pwd  0 inval-pwd)
form=dynamic_37                   guesses: 1489 -show=1489 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_37               guesses: 1487 -show=1487 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1485 val-pwd  2 inval-pwd)
.pot CHK:dynamic_39               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1500 val-pwd  1 inval-pwd)
form=dynamic_50                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_50               guesses: 1486 -show=1486 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1432 val-pwd  42 inval-pwd)
.pot CHK:dynamic_51               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1498 val-pwd  1 inval-pwd)
.pot CHK:dynamic_52               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1496 val-pwd  2 inval-pwd)
form=dynamic_53                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_53               guesses: 1488 -show=1488 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1438 val-pwd  33 inval-pwd)
form=dynamic_54                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_54               guesses: 1489 -show=1489 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1436 val-pwd  38 inval-pwd)
form=dynamic_55                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_55               guesses: 1484 -show=1484 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1480 val-pwd  2 inval-pwd)
form=dynamic_56                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_56               guesses: 1485 -show=1485 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1481 val-pwd  2 inval-pwd)
form=dynamic_57                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_57               guesses: 1486 -show=1486 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1486 val-pwd  0 inval-pwd)
form=dynamic_58                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_58               guesses: 1485 -show=1485 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1434 val-pwd  36 inval-pwd)
form=dynamic_60                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_60               guesses: 1486 -show=1486 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1439 val-pwd  38 inval-pwd)
.pot CHK:dynamic_61               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1498 val-pwd  1 inval-pwd)
form=formspring                   guesses:  879 -show= 879 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_62               guesses: 1500 -show=1500 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1498 val-pwd  2 inval-pwd)
form=dynamic_63                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_63               guesses: 1489 -show=1489 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1430 val-pwd  43 inval-pwd)
form=dynamic_64                   guesses: 1493 -show=1493 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED1!!!]
.pot CHK:dynamic_64               guesses: 1490 -show=1490 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (1437 val-pwd  40 inval-pwd)
...

@jfoug
Copy link
Collaborator

jfoug commented Mar 4, 2015

I guess I am going to have to bite the bullet, and simply change code in jtrts.pl to strip out any -fork code for the .pot check, since you continue to post pretty much the same type bugs on this one. So if running in -fork mode, -fork will be used properly on the 'real' cracking session (which writes data to the .pot file). But -fork mode will not be used when reprocessing the .pot file, which in of itself has been changed to be more aggressive into finding cases where the password stored in the .pot file is not the correct one, BUT which has problems that can NOT be worked around fully due to expectations of screen IO and the problem interaction we get with -fork and running with memdbg. Now that you were also getting this when running in non -memdbg is a bit curious, but like you said, it may be OS related.

Using -fork for the .pot re-run is not a great thing, and provides no additional benefit, but causes numerous bad things to happen, since we are reading a mix of writing to the stdout, and not all of it is from the password guessing code. On the initial run, all data comes from .pot file, and all of that is being done with flocking, and flushing of writes (or 'should' be). The main run is what is important anyway. That is what we really should be testing against.

What you show for -jumbo-1 is expected. There were known problems, which have been fixed since that time, with the fflush(.potfile) since that time.

@frank-dittrich
Copy link
Collaborator Author

With memdbg and asan disabled, I got

(master)test $ ./jtrts.pl -type=dynamic -passthru="--fork=32" -stoponerror -v -v|head
-------------------------------------------------------------------------------
- JtR-TestSuite (jtrts). Version 1.13, Dec 21, 2014.  By, Jim Fougeron & others
- Testing:  John the Ripper password cracker, version 1.8.0.2-jumbo-1-bleeding_omp [linux-gnu 64-bit AVX-autoconf]
--------------------------------------------------------------------------------
...
Dv!hpppp^[4]     (Dv!hpppp^[4])
Warning: detected hash type "dynamic_0", but the string is also recognized as "Raw-MD5"
Use the "--format=Raw-MD5" option to force loading these as that type instead
Warning: OpenMP was disabled due to --fork; a non-OpenMP build may be faster
Node numbers 1-32 of 32 (fork)
Press 'q' or Ctrl-C to abort, almost any other key for status
21 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s }QM{ppppppppppb0yc..~-2Fpp2%{}
7 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s ]fokpppppppppppz|;Q..M-pzpppp-h}[
13 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s _='mpppppppppppppppppppppppppppppppppppppppppppp8[cH..SW=Xpppo_eC
2 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s H8{Oppppppppp*eHQ..}6,cppppppppppppppppppppppDN'%
5 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s V&_Jppppppppppppppppppppppppppppppp{;nu..R|74pppppppppp2F4[
23 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s XS/Qp JqX..!uIApppppppbY/q
14 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s EopZppppppppppppppppppppppppppyNmE..xN}%ppppppp>Su)
15 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s 2~/[ppppp(db6..m=%2pppppgIHb
9 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s hlH3pppppppppppppppppL7rO..+r/4pppppppppppppppppppppppppppppppppppppppp#L[a
10 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s gUO=ppppppppppppppppppppppiEk<..(ymTpppppppppppppppppppppppppppppppppppppppppN$]K
4 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s Jebrpppppppppppppppppppppppppppppppw~jk..kk}|ppppppppppppppppppppppppppppppppppppppppppB*Qe
6 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s RJ(\ppppppppppppppppppppppppppppp6eFx..<L3*pppppppppppppppppppppppppppppppppppppppppppo.P-
22 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s {BA"ppppppppp]cl`..[IHvppppppppJe;!
16 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s lDp$pppppppppiL]u..)lo4m%=
3 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s `+itppppppppp~jt9..TQ{Wppppppppppppppppppr"x/
27 28g 0:00:00:00 DONE (2015-03-04 15:46) 933.3g/s 933.3p/s 933.3c/s 858666C/s MCy|GK#..Xlu'pppppppppppppppppppppppppppppppppppppppppDt"5
8 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s }~%^ppppppppppppppppppppppppppppppppppppppppppp|Au)..#.B>ppppppppppppppppppppppOFIY
31 28g 0:00:00:00 DONE (2015-03-04 15:46) 933.3g/s 933.3p/s 933.3c/s 858666C/s p^$?pppppppppppppppppppppppppppppppppppppp*_w?..7!,"pppppppppppppppppppppppppppppppppppu{Nr
20 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s Vl93pp^>J%..?uJ[pppppppppFbG(
17 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s `|BVppppWoDY..Jj`~pp@v3=
11 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s %2r(ppppppppppppppppppp5d&[..K[h'p�ppppp�ppppp�ppppp�SK*y
18 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s "j^-ppppppd._L..n$u<p�ppppp�/.)O
1 29g 0:00:00:00 DONE (2015-03-04 15:46) 725.0g/s 725.0p/s 725.0c/s 667000C/s ;C>5ppt^q^..ooGipppppppppppppppppppppppppppppppppppppp.Q~<
Waiting for 31 children to terminate
12 29g 0:00:00:00 DONE (2015-03-04 15:46) 1450g/s 1450p/s 1450c/s 1334KC/s @+%%pppppppppppppppppppppppppppppppppppppZ1/J..jdBJpp%4!A
30 28g 0:00:00:00 DONE (2015-03-04 15:46) 1400g/s 1400p/s 1400c/s 1288KC/s mc?5pppppppppppppppppppppppppppppppppppppppppxA>t..h0F7pppppppppppppppppppppppppppppppppppppp{N-\
29 28g 0:00:00:00 DONE (2015-03-04 15:46) 1400g/s 1400p/s 1400c/s 1288KC/s Yh]Ipppppppppk6DY..uxgRppppppH}2G
26 28g 0:00:00:00 DONE (2015-03-04 15:46) 933.3g/s 933.3p/s 933.3c/s 858666C/s 7[hMppiQs*..<RJ8pppppppppppppppppppppppppppppppppppppNWBw
24 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s Y2Dypp[y"L..#Z{Zpppp ^mp
32 28g 0:00:00:00 DONE (2015-03-04 15:46) 933.3g/s 933.3p/s 933.3c/s 858666C/s EyyDppppppppp2~}D..hviippppppd"%A
25 28g 0:00:00:00 DONE (2015-03-04 15:46) 1400g/s 1400p/s 1400c/s 1288KC/s dRb%pppppppp=<d8..Dv!hpppp^[4]
28 28g 0:00:00:00 DONE (2015-03-04 15:46) 1400g/s 1400p/s 1400c/s 1288KC/s LaZIppppp6QQU..knGn
19 29g 0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s @bZ%pppppQU0u..sGqqpK#[u
Use the "--show" option to display all of the cracked passwords reliably
Session completed


FAILED line = guesses: 29  0:00:00:00 DONE (2015-03-04 15:46) 966.6g/s 966.6p/s 966.6c/s 889333C/s EopZppppppppppppppppppppppppppyNmE..xN}%ppppppp>Su)
Execute john: ../run/john -show    -pot=./tst.pot dynamic_0_new_tst.in -form=dynamic_0 2>&1

d_show_line2 = 
920 password hashes cracked, 580 left
1 invalid passwords
920 valid passwords

.pot CHK:dynamic_0                guesses:  920 -show= 920 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (920 val-pwd  1 inval-pwd)
Exiting on error. The .pot file ./tst.pot contains the found data
The command used to run this test was:

../run/john -ses=./tst  --fork=32 -pot=./tst.pot dynamic_0_new_tst.in --wordlist=pw-new.dic

@frank-dittrich
Copy link
Collaborator Author

In a repeated run, it got to dynamic_6 before failing:

FAILED line = guesses: 29  0:00:00:00 DONE (2015-03-04 15:48) 725.0g/s 725.0p/s 667000c/s 667000C/s eI"7pppppppp?#R@..xN}%ppppppp>Su)
Execute john: ../run/john -show    -pot=./tst.pot dynamic_6_new_tst.in -form=dynamic_6 2>&1

d_show_line2 = 
920 password hashes cracked, 580 left
1 invalid passwords
920 valid passwords

.pot CHK:dynamic_6                guesses:  920 -show= 920 0:00:00:00 DONE : Expected count(s) (1500)  [!!!FAILED4!!!]  (920 val-pwd  1 inval-pwd)
Exiting on error. The .pot file ./tst.pot contains the found data
The command used to run this test was:

../run/john -ses=./tst  --fork=32 -pot=./tst.pot dynamic_6_new_tst.in --wordlist=pw-new.dic

@frank-dittrich
Copy link
Collaborator Author

I guess it is a TS bug and your parsing logic is wrong.

FAILED line = guesses: 29  0:00:00:00 DONE (2015-03-04 16:23) 580.0g/s 580.0p/s 535340c/s 535340C/s o5L}>+g..s7g9y)
FAILED line = guesses: 47  0:00:00:00 DONE (2015-03-04 16:23) 1566g/s 1566p/s 1566c/s 2350KC/s hlH3pppppppppppppppppL7rO..?ziypppppG"Z)
FAILED line = guesses: 28  0:00:00:00 DONE (2015-03-04 16:24) 1400g/s 1400p/s 1400c/s 1288KC/s |f"4$8..Et9tppppppppppppppppgSF)

Apparently, these are always summary lines of forked processes where the last password of the last chunk of passwords ends with a ) character.

@jfoug
Copy link
Collaborator

jfoug commented Mar 4, 2015

It is not a really TS bug, it is a JtR 'bug' side effect of forking. It is where screen output gets smashed.

But this is happening in the real run, and not the .pot recheck? It may be that the fork 'guesses' line outputs are smashing each other.

I will not be chasing these 'phantom' bugs any more. -fork is not highly compatible with the TS. The TS is a tool to help make sure that jtr is finding all passwords. The last 10-15 'bugs' found with -fork have not been bugs. Yes, we found some -asan related things, that really needed fixed. But most of these are nothing more than side effects of garbled screen output, and how jtrts.pl was written to work.

If you are going to continue to find pretty much the exact same 'bug', then simply continue to add to this bug. List exact build type, the exact jtrts.pl command line used, the OS, etc. I will look at possibly re-writing the inner logic of the cracking loop in jtrts.pl at some time, but not right now.

@jfoug
Copy link
Collaborator

jfoug commented Mar 4, 2015

The ones that 'appear' to be side effects of how the TS is coded, probably should only go on the TS. I really doubt if you ran all of these formats by hand, using the --fork=xx, that there would be any passwords 'missing'. That is the main point of what we should focus on with the testing within TS against JtR. IF we have problems where only 1456 are found, when 1500 should be, AND when we run the file by hand we also see that only 1456 ARE being found, then that certainly IS a bug in that format of JtR (or in JtR proper). But if JtR is finding the right data, and it is simply the TS complaining, then we should put it over in TS like you did with #45.

@frank-dittrich
Copy link
Collaborator Author

Closing, because if there's anything wrong here it is the TS parsing logic, see openwall/john-tests#45

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants