openwall / john

John the Ripper jumbo - advanced offline password cracker, which supports hundreds of hash and cipher types, and runs on many operating systems, CPUs, GPUs, and even some FPGAs
https://www.openwall.com/john/
Other
10.14k stars 2.08k forks source link

Segmentation fault (core dumped) using dynamic format #3564

Open jeroen-80 opened 5 years ago

jeroen-80 commented 5 years ago

As a follow-up for #3417. Just finished full test of the fix. No more stack smashing errors but a segfault when the session is almost completed:

..
Almost done: Processing the remaining buffered candidate passwords, if any
1: Warning: Only 20 candidates buffered for the current salt, minimum 48
needed for performance.
1: Warning: Only 17 candidates buffered for the current salt, minimum 48
needed for performance.
1: Warning: Only 11 candidates buffered for the current salt, minimum 48
needed for performance.
1: Warning: Only 26 candidates buffered for the current salt, minimum 48
needed for performance.
1: Warning: Only 32 candidates buffered for the current salt, minimum 48
needed for performance.
1: Warning: Only 30 candidates buffered for the current salt, minimum 48
needed for performance.
1: Warning: Only 39 candidates buffered for the current salt, minimum 48
needed for performance.
1: Warning: Only 37 candidates buffered for the current salt, minimum 48
needed for performance.
1: Warning: Only 46 candidates buffered for the current salt, minimum 48
needed for performance.
1: Warning: Only 47 candidates buffered for the current salt, minimum 48
needed for performance.
1: Further messages of this type will be suppressed.
To see less of these warnings in the future, enable 'RelaxKPCWarningCheck'
in john.conf
Segmentation fault (core dumped)

Any advice about how to supply you with useful debug info? Thank you.

jeroen-80 commented 5 years ago

And a stack smashing variant after a john --restore:

3: Warning: Only 17 candidates buffered for the current salt, minimum 48
needed for performance.
3: Warning: Only 38 candidates buffered for the current salt, minimum 48
needed for performance.
3: Warning: Only 17 candidates buffered for the current salt, minimum 48
needed for performance.
3: Warning: Only 38 candidates buffered for the current salt, minimum 48
needed for performance.
3: Warning: Only 6 candidates buffered for the current salt, minimum 48
needed for performance.
3: Further messages of this type will be suppressed.
Almost done: Processing the remaining buffered candidate passwords, if any
4: Warning: Only 6 candidates buffered for the current salt, minimum 48
needed for performance.
4: Warning: Only 26 candidates buffered for the current salt, minimum 48
needed for performance.
4: Warning: Only 38 candidates buffered for the current salt, minimum 48
needed for performance.
4: Warning: Only 6 candidates buffered for the current salt, minimum 48
needed for performance.
4: Warning: Only 38 candidates buffered for the current salt, minimum 48
needed for performance.
4: Warning: Only 17 candidates buffered for the current salt, minimum 48
needed for performance.
4: Warning: Only 38 candidates buffered for the current salt, minimum 48
needed for performance.
4: Warning: Only 17 candidates buffered for the current salt, minimum 48
needed for performance.
4: Warning: Only 38 candidates buffered for the current salt, minimum 48
needed for performance.
4: Warning: Only 6 candidates buffered for the current salt, minimum 48
needed for performance.
4: Further messages of this type will be suppressed.
3 8512g 0:17:34:05 99.91% (ETA: 12:00:29) 0.1345g/s 381983p/s 797709c/s 365814KC/s <removed>
4 15103g 0:23:18:01 99.91% (ETA: 12:00:47) 0.1800g/s 284296p/s 853408c/s 272868KC/s <removed>
2 12264g 0:20:43:05 99.91% (ETA: 12:00:39) 0.1644g/s 325343p/s 830205c/s 311142KC/s <removed>
1 23805g 1:05:43:04 99.91% (ETA: 12:01:07) 0.2225g/s 222219p/s 920292c/s 213521KC/s <removed>
*** stack smashing detected ***: ./john terminated
*** stack smashing detected ***: ./john terminated
Aborted (core dumped)
bofh@dev:/opt/JohnTheRipper-bleeding-jumbo/run$ *** stack smashing detected ***: ./john terminated
*** stack smashing detected ***: ./john terminated

Please note that all of four threads except one were already finished for quite some time but do not indicate 100% or DONE. Maybe waiting for a final check or perhaps related to the issue?

jfoug commented 5 years ago

what were your command lines from above problems?

jeroen-80 commented 5 years ago

First post: ./john --single --fork=4 --format=dynamic_12 hashfile.txt. Second post: ./john --restore (restore from the segfaulted session). Input hashfile.txt contains many million entries.

Similar runs with fewer hashes and other dynamic format also show interesting behavior when near completion:

..
1: Warning: Only 41 candidates buffered for the current salt, minimum 48
needed for performance.
1: Further messages of this type will be suppressed.
To see less of these warnings in the future, enable 'RelaxKPCWarningCheck'
in john.conf
1 8632g 0:02:26:49 DONE (2018-12-28 16:14) 0.9798g/s 445468p/s 898237c/s 32559KC/s <removed>..<removed>
Waiting for 3 children to terminate
<wait forever>

This run was also started with a --single --fork=4. When the last cracking process is finished, 2 processes keep on running at 100% CPU and never end. In this case the input was limited to about 600k hashes.

magnumripper commented 5 years ago

When the last cracking process is finished, 2 processes keep on running at 100% CPU and never end. In this case the input was limited to about 600k hashes.

When this happens, you could do a pgrep john to see their pids, then start gdb attach <pid> using one of the pids. Then type bt for a backtrace. Looks like this (from an incremental run):

(gdb) bt
#0  _mm_andnot_si128 (_data=<value optimized out>, out=0x7fffca9f4fd0, reload_state=0x7fffca9f4fd0, 
    SSEi_flags=1545) at /usr/lib/gcc/x86_64-redhat-linux/4.4.7/include/emmintrin.h:1239
#1  SIMDmd5body (_data=<value optimized out>, out=0x7fffca9f4fd0, reload_state=0x7fffca9f4fd0, 
    SSEi_flags=1545) at simd-intrinsics.c:292
#2  0x0000000000495384 in DoMD5_crypt_f_sse (in=<value optimized out>, len=<value optimized out>, 
    out=0x3fee3a0) at dynamic_big_crypt.c:641
#3  0x00000000004957f9 in DynamicFunc__MD5_crypt_input1_to_output1_FINAL ()
    at dynamic_big_crypt.c:1089
#4  0x000000000048ba1f in crypt_all (pcount=<value optimized out>, salt=<value optimized out>)
    at dynamic_fmt.c:1826
#5  0x00000000006d866a in crk_password_loop (salt=0x3f9a520) at cracker.c:855
#6  0x00000000006d9ed5 in crk_salt_loop () at cracker.c:1020
#7  0x00000000006e1d39 in inc_key_loop (db=0x1f49420, mode=<value optimized out>) at inc.c:426
#8  do_incremental_crack (db=0x1f49420, mode=<value optimized out>) at inc.c:888
#9  0x00000000006e5a15 in john_run () at john.c:1853
#10 0x00000000006e6abd in main (argc=<value optimized out>, argv=<value optimized out>) at john.c:2102

Typing c and enter will let it run again and after pressing ctrl-c you can do a new bt in case the first one was unlucky not to show "what" JtR is doing. Typing detach and then q will get you out of the debugger.

magnumripper commented 5 years ago

BTW I think you could also get them to output status lines using pkill -usr1 john. Or even simpler: See what the log says (perhaps they have rules left?) at that stage.

jeroen-80 commented 5 years ago

So basically there are two issue that might be related (at least they seem to show up at the same point in the cracking process):

magnumripper commented 5 years ago

If you find some reproducible situation that always segfaults (eg. a particular session that segfaults if you try and resume it) you can run john through the same debugger: Just add gdb --args before your normal command line, eg. gdb --args ./john hashfile (...) or gdb --args ./john -resume:name. In both cases, the debugger will start and give you a prompt. Once you say r (for run) and press enter, everything runs as usual but under the wings of the debugger. Once it segfaults, the debugger will tell some info about what happened and freeze everything there. If you didn't already get a backtrace, you can ask for one with bt. As a programmer one can also print different variables and pointers and get a clue what happened but a backtrace is often enough for us to see exactly where something hit the fan.

jeroen-80 commented 5 years ago

Situation: dozens of threads cracking in wordlist mode, large number of dynamic type hashes. After some time, john seems unresponsive (no response when e.g. enter is pressed for status). Trace:


Attaching to process 40940
Reading symbols from /opt/JohnTheRipper-bleeding-jumbo/run/john...done.
Reading symbols from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libm.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libm-2.23.so...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libz.so.1...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libdl.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libdl-2.23.so...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libcrypt.so.1...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libcrypt-2.23.so...done.
done.
Reading symbols from /usr/lib/x86_64-linux-gnu/libgomp.so.1...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libpthread.so.0...Reading symbols from /usr/lib/debug/.build-id/ce/17e023542265fc11d9bc8f534bb4f070493d30.debug...done.
done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libc-2.23.so...done.
done.
Reading symbols from /lib64/ld-linux-x86-64.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/ld-2.23.so...done.
done.
0x00000000006afd64 in crk_remove_pot_entry (ciphertext=0x7fff0bc4abf0 "$dynamic_1007$<hash removed>$<salt removed>") at cracker.c:546
546                     if (!dyna_salt_cmp(pot_salt, salt->salt, crk_params->salt_size))
(gdb) bt
#0  0x00000000006afd64 in crk_remove_pot_entry (ciphertext=0x7fff0bc4abf0 "$dynamic_1007$<hash removed>$<salt removed>") at cracker.c:546
#1  crk_reload_pot () at cracker.c:660
#2  0x00000000006b02c5 in crk_salt_loop () at cracker.c:994
#3  0x00000000006e809c in do_wordlist_crack (db=db@entry=0x1deffa0 <database>, name=<optimized out>, rules=<optimized out>) at wordlist.c:1444
#4  0x00000000006bd082 in john_run () at john.c:1843
#5  main (argc=<optimized out>, argv=<optimized out>) at john.c:2102
Attaching to process 40940
Reading symbols from /opt/JohnTheRipper-bleeding-jumbo/run/john...done.
Reading symbols from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libm.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libm-2.23.so...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libz.so.1...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libdl.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libdl-2.23.so...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libcrypt.so.1...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libcrypt-2.23.so...done.
done.
Reading symbols from /usr/lib/x86_64-linux-gnu/libgomp.so.1...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libpthread.so.0...Reading symbols from /usr/lib/debug/.build-id/ce/17e023542265fc11d9bc8f534bb4f070493d30.debug...done.
done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libc-2.23.so...done.
done.
Reading symbols from /lib64/ld-linux-x86-64.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/ld-2.23.so...done.
done.
0x00000000006afd64 in crk_remove_pot_entry (ciphertext=0x7fff0bc4abf0 "$dynamic_1007$<hash removed>$<salt removed>") at cracker.c:546
546                     if (!dyna_salt_cmp(pot_salt, salt->salt, crk_params->salt_size))
(gdb) bt
#0  0x00000000006afd64 in crk_remove_pot_entry (ciphertext=0x7fff0bc4abf0 "$dynamic_1007$<hash removed>$<salt removed>") at cracker.c:546
#1  crk_reload_pot () at cracker.c:660
#2  0x00000000006b02c5 in crk_salt_loop () at cracker.c:994
#3  0x00000000006e809c in do_wordlist_crack (db=db@entry=0x1deffa0 <database>, name=<optimized out>, rules=<optimized out>) at wordlist.c:1444
#4  0x00000000006bd082 in john_run () at john.c:1843
#5  main (argc=<optimized out>, argv=<optimized out>) at john.c:2102Attaching to process 40940
Reading symbols from /opt/JohnTheRipper-bleeding-jumbo/run/john...done.
Reading symbols from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libm.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libm-2.23.so...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libz.so.1...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libdl.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libdl-2.23.so...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libcrypt.so.1...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libcrypt-2.23.so...done.
done.
Reading symbols from /usr/lib/x86_64-linux-gnu/libgomp.so.1...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libpthread.so.0...Reading symbols from /usr/lib/debug/.build-id/ce/17e023542265fc11d9bc8f534bb4f070493d30.debug...done.
done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libc-2.23.so...done.
done.
Reading symbols from /lib64/ld-linux-x86-64.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/ld-2.23.so...done.
done.
0x00000000006afd64 in crk_remove_pot_entry (ciphertext=0x7fff0bc4abf0 "$dynamic_1007$<hash removed>$<salt removed>") at cracker.c:546
546                     if (!dyna_salt_cmp(pot_salt, salt->salt, crk_params->salt_size))
(gdb) bt
#0  0x00000000006afd64 in crk_remove_pot_entry (ciphertext=0x7fff0bc4abf0 "$dynamic_1007$<hash removed>$<salt removed>") at cracker.c:546
#1  crk_reload_pot () at cracker.c:660
#2  0x00000000006b02c5 in crk_salt_loop () at cracker.c:994
#3  0x00000000006e809c in do_wordlist_crack (db=db@entry=0x1deffa0 <database>, name=<optimized out>, rules=<optimized out>) at wordlist.c:1444
#4  0x00000000006bd082 in john_run () at john.c:1843
#5  main (argc=<optimized out>, argv=<optimized out>) at john.c:2102Attaching to process 40940
Reading symbols from /opt/JohnTheRipper-bleeding-jumbo/run/john...done.
Reading symbols from /lib/x86_64-linux-gnu/libcrypto.so.1.0.0...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libm.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libm-2.23.so...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libz.so.1...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libdl.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libdl-2.23.so...done.
done.
Reading symbols from /lib/x86_64-linux-gnu/libcrypt.so.1...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libcrypt-2.23.so...done.
done.
Reading symbols from /usr/lib/x86_64-linux-gnu/libgomp.so.1...(no debugging symbols found)...done.
Reading symbols from /lib/x86_64-linux-gnu/libpthread.so.0...Reading symbols from /usr/lib/debug/.build-id/ce/17e023542265fc11d9bc8f534bb4f070493d30.debug...done.
done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/libc-2.23.so...done.
done.
Reading symbols from /lib64/ld-linux-x86-64.so.2...Reading symbols from /usr/lib/debug//lib/x86_64-linux-gnu/ld-2.23.so...done.
done.
0x00000000006afd64 in crk_remove_pot_entry (ciphertext=0x7fff0bc4abf0 "$dynamic_1007$<hash removed>$<salt removed>") at cracker.c:546
546                     if (!dyna_salt_cmp(pot_salt, salt->salt, crk_params->salt_size))
(gdb) bt
#0  0x00000000006afd64 in crk_remove_pot_entry (ciphertext=0x7fff0bc4abf0 "$dynamic_1007$<hash removed>$<salt removed>") at cracker.c:546
#1  crk_reload_pot () at cracker.c:660
#2  0x00000000006b02c5 in crk_salt_loop () at cracker.c:994
#3  0x00000000006e809c in do_wordlist_crack (db=db@entry=0x1deffa0 <database>, name=<optimized out>, rules=<optimized out>) at wordlist.c:1444
#4  0x00000000006bd082 in john_run () at john.c:1843
#5  main (argc=<optimized out>, argv=<optimized out>) at john.c:2102