331515 - selfserv Bus error on 3DES ciphersuites

Status: RESOLVED FIXED

(NSS :: Tools, defect, P1)

Description

[Alexei Volkov]

Tonight nightly testing reported 8 failures on selfserv side.
cores are on solaris 9 and 10 sparc 64 bit. Stacks are the same:

=>[1] DES_Do1Block(ks = ???, inbuf = ???, outbuf = ???) (optimized), at 0xffffffff7c427880 (line ~667) in "des.c"
  [2] DES_EDE3_ECB(cx = ???, out = ???, in = ???, len = ???) (optimized), at 0xffffffff7c425be0 (line ~94) in "desblapi.c"
  [3] DES_Encrypt(cx = ???, out = ???, outLen = ???, maxOutLen = ???, in = ???, inLen = ???) (optimized), at 0xffffffff7c4268c8 (line ~280) in "desblapi.c"
  [4] DES_Encrypt(cx = 0x10031d8f0, output = 0xffffffff7b4f802b "", outputLen = 0xffffffff7b4f7c1c, maxOutputLen = 429U, input = 0x10026c3e0 "^B@b\x92O%^A^Z7\xf8^M\xbf\xe9d\xf2u\xae\xdf7^Hz\xc4\xf74", inputLen = 24U), line 633 in "loader.c"
  [5] NSC_Encrypt(hSession = 62U, pData = 0x10026c3e0 "^B@b\x92O%^A^Z7\xf8^M\xbf\xe9d\xf2u\xae\xdf7^Hz\xc4\xf74", ulDataLen = 24U, pEncryptedData = 0xffffffff7b4f802b "", pulEncryptedDataLen = 0xffffffff7b4f7e90), line 902 in "pkcs11c.c"
  [6] NSC_WrapKey(hSession = 62U, pMechanism = 0xffffffff7b4f7e68, hWrappingKey = 10U, hKey = 9U, pWrappedKey = 0xffffffff7b4f802b "", pulWrappedKeyLen = 0xffffffff7b4f7e90), line 3996 in "pkcs11c.c"
  [7] PK11_WrapSymKey(type = 306U, param = 0x10025c1a0, wrappingKey = 0x1003218f0, symKey = 0x10026e100, wrappedKey = 0xffffffff7b4f8210), line 1285 in "pk11skey.c"
  [8] getWrappingKey(ss = 0x1002b8160, masterSecretSlot = 0x10022f780, exchKeyType = ssl_kea_ecdh, masterWrapMech = 306U, pwArg = (nil)), line 3884 in "ssl3con.c"
  [9] ssl3_CacheWrappedMasterSecret(ss = 0x1002b8160, effectiveExchKeyType = ssl_kea_ecdh), line 7153 in "ssl3con.c"
  [10] ssl3_HandleFinished(ss = 0x1002b8160, b = 0x1002bf874 "a\xe0#\xf6\xa9\xae\xbe.V\x936d^T\xa1J\xd6\x94\x96^OB\xf6n\xf4^K\xb7|SV:N^A\x8d^K^K^K^K^K^K^K^K^K^K^K^K\xf9i\xa4\xa0\xcd\x93\xf4^Nh\x8bD\x8d\xdc>\xf4cO\xe1\xe5\xe1\xdf\xb7", length = 12U, hashes = 0xffffffff7b4f858c), line 7314 in "ssl3con.c"
  [11] ssl3_HandleHandshakeMessage(ss = 0x1002b8160, b = 0x1002bf874 "a\xe0#\xf6\xa9\xae\xbe.V\x936d^T\xa1J\xd6\x94\x96^OB\xf6n\xf4^K\xb7|SV:N^A\x8d^K^K^K^K^K^K^K^K^K^K^K^K\xf9i\xa4\xa0\xcd\x93\xf4^Nh\x8bD\x8d\xdc>\xf4cO\xe1\xe5\xe1\xdf\xb7", length = 12U), line 7489 in "ssl3con.c"
  [12] ssl3_HandleHandshake(ss = 0x1002b8160, origBuf = 0x1002b84a8), line 7557 in "ssl3con.c"
  [13] ssl3_HandleRecord(ss = 0x1002b8160, cText = 0xffffffff7b4f8900, databuf = 0x1002b84a8), line 7820 in "ssl3con.c"
  [14] ssl3_GatherCompleteHandshake(ss = 0x1002b8160, flags = 0), line 206 in "ssl3gthr.c"
  [15] ssl_GatherRecord1stHandshake(ss = 0x1002b8160), line 1260 in "sslcon.c"
  [16] ssl_Do1stHandshake(ss = 0x1002b8160), line 149 in "sslsecur.c"
  [17] ssl_SecureRecv(ss = 0x1002b8160, buf = 0xffffffff7b4f91c8 "", len = 10239, flags = 0), line 1038 in "sslsecur.c"
  [18] ssl_SecureRead(ss = 0x1002b8160, buf = 0xffffffff7b4f91c8 "", len = 10239), line 1057 in "sslsecur.c"
  [19] ssl_Read(fd = 0x1001337f0, buf = 0xffffffff7b4f91c8, len = 10239), line 1387 in "sslsock.c"
  [20] PR_Read(fd = 0x1001337f0, buf = 0xffffffff7b4f91c8, amount = 10239), line 141 in "priometh.c"
  [21] handle_connection(tcp_sock = 0x1001337f0, model_sock = 0x100132af0, requestCert = 0), line 954 in "selfserv.c"
  [22] jobLoop(a = (nil), b = (nil), c = 0), line 517 in "selfserv.c"
  [23] thread_wrapper(arg = 0x100240750), line 485 in "selfserv.c"
  [24] _pt_root(arg = 0x10024b9f0), line 220 in "ptthread.c"



ssl.sh: Stress SSL3 ECDHE-ECDSA AES 128 CBC with SHA (no reuse) ----
selfserv -D -p 8444 -d ../ext_server -n mace.red.iplanet.com  \
         -e mace.red.iplanet.com-ec -w nss -c :C009 -i ../tests_pid.2117  &
selfserv started at Thu Mar 23 03:47:10 PST 2006
tstclnt -p 8444 -h mace.red.iplanet.com -B -s -q \
        -d ../ext_client < /share/builds/mccrel3/security/securitytip/builds/20
060323.1/wozzeck_Solaris8/mozilla/security/nss/tests/ssl/sslreq.dat
strsclnt -q -p 8444 -d ../ext_client -B -s -w nss -c 10 -C :C009 -N -T \        
          mace.red.iplanet.com
strsclnt started at Thu Mar 23 03:47:10 PST 2006
strsclnt: -- SSL: Server Certificate Validated.
strsclnt: -- SSL: Server Certificate Validated.
strsclnt: -- SSL: Server Certificate Validated.
strsclnt: 0 cache hits; 8 cache misses, 0 cache not reusable
strsclnt: -- SSL: Server Certificate Validated.
strsclnt: -- SSL: Server Certificate Validated.
strsclnt: -- SSL: Server Certificate Validated.
active_threads set down to 6
strsclnt: PR_Write returned error -5938:
Encountered end of file.
active_threads set down to 5
strsclnt: PR_Write returned error -5938:
Encountered end of file.
strsclnt: PR_Write returned error -5938:
Encountered end of file.
strsclnt: PR_Write returned error -5938:
Encountered end of file.
strsclnt: PR_Write returned error -5938:
Encountered end of file.
strsclnt: PR_Write returned error -5938:
Encountered end of file.
strsclnt: PR_Write returned error -5938:
Encountered end of file.
strsclnt: Client timed out waiting for connection to server.
18470 Bus Error - core dumped

Comment 1

[Julien Pierre]

Alexei,

Did this happen on any debug build by any chance ?
Are you certain this is the stack of the thread that crashed ?

Also, do we know if this same failure happened before last night ?

Comment 2

[Alexei Volkov]

Attachment: bus error fix patch

memory misalignment in ssl3con.c was the reason of the failure. Wrapped key output data pointer was set to point to misaligned start address depending on values in  ecWrapped->encodedParamLen and ecWrapped->pubValueLen variables.

Comment 3

[Robert Relyea]

Good work alexei.

Question, isn't there a macro to calculate alignment? I know freebl does some memory alignment.

Also, should we force alignment to a stricter boundary (32 or 64 or sizeof(int) or some such boundary)?

bob

Comment 4

[Alexei Volkov]

Attachment: bus error fix patch

memory misalignment in ssl3con.c was the reason of the failure. Wrapped key output data pointer was set to point to misaligned start address depending on values in  ecWrapped->encodedParamLen and ecWrapped->pubValueLen variables.

Comment 5

[Alexei Volkov]

Comment on attachment 216466 [details] [diff] [review]
bus error fix patch

sorry, clicked extra time

Comment 6

[Alexei Volkov]

Comment on attachment 216475 [details] [diff] [review]
bus error fix patch

going to look for mem alignment macro and resubmit the patch

Comment 7

[Nelson Bolyard (seldom reads bugmail)]

Comment on attachment 216466 [details] [diff] [review]
bus error fix patch

Wait a minute.  Unless I'm misunderstanding this patch, this patch 
suggests that you believe that PK11_WrapSymKey and PK11_UnwrapSymKey 
require that the data buffer pointer in the SECItem for the wrapped 
key must be aligned somehow.  If that is indeed the problem, then 
there is a grave error in the implementations of those functions.

A wrapped key is a string of unsigned chars, all encrypted. 
No alignment may be required for such a string.
Any code that fails because this octet string pointer was not aligned 
is itself broken.  The solution is not to force callers to align their
buffers for encrypted data strings.  The solution is to fix the 
underlying code, so that it no longer requires alignment of those 
buffers.  

Aside: our "bltest" program tests all our symmetric ciphers for 
proper operation with unaligned source and destination pointers.
But I'll bet that our PKCS#11 test programs do not have any similar
unaligned buffer testing.  If I'm right, such tests should be 
implemented with all due haste.

Comment 8

[Robert Relyea]

Are you sure blapitest is testing for unaligned access in DES? all.sh logs show the following tests are run:

cipher.sh: DES ECB Encrypt --------------------------------
bltest -T -m des_ecb -E -d .
Encryption self-test for des_ecb passed.
cipher.sh: DES ECB Decrypt --------------------------------
bltest -T -m des_ecb -D -d .
Decryption self-test for des_ecb passed.
cipher.sh: DES CBC Encrypt --------------------------------
bltest -T -m des_cbc -E -d .
Encryption self-test for des_cbc passed.
cipher.sh: DES CBC Decrypt --------------------------------
bltest -T -m des_cbc -D -d .
Decryption self-test for des_cbc passed.
cipher.sh: DES3 ECB Encrypt --------------------------------
bltest -T -m des3_ecb -E -d .
Encryption self-test for des3_ecb passed.
cipher.sh: DES3 ECB Decrypt --------------------------------
bltest -T -m des3_ecb -D -d .
Decryption self-test for des3_ecb passed.
cipher.sh: DES3 CBC Encrypt --------------------------------
bltest -T -m des3_cbc -E -d .
Encryption self-test for des3_cbc passed.
cipher.sh: DES3 CBC Decrypt --------------------------------
bltest -T -m des3_cbc -D -d .
Decryption self-test for des3_cbc passed.

 When I run it on my machine I get:

 Both the output and the input look pretty aligned in these tests (the seem to be aligned to a 32-bit boundary).

(gdb) run -T -m des_ecb -E -d .
warning: cannot close "shared object read from target memory": File in wrong format
Starting program: /home/rrelyea/builds/nsstip/mozilla/dist/Linux2.6_x86_glibc_PTH_DBG.OBJ/bin/bltest -T -m des_ecb -E -d .
Reading symbols from shared object read from target memory...done.
Loaded system supplied DSO at 0xfc2000
[Thread debugging using libthread_db enabled]
[New Thread -1208768832 (LWP 21999)]
Detaching after fork from child process 22023.
[Switching to Thread -1208768832 (LWP 21999)]

Breakpoint 2, DES_Encrypt (cx=0x8cfdd70, output=0x8cfccf8 "",
    outputLen=0xbfc525cc, maxOutputLen=8, input=0x8cfcce8 "Mozilla!",
    inputLen=8) at loader.c:630
630       if (!vector && PR_SUCCESS != freebl_RunLoaderOnce())
(gdb) cont
Continuing.
Encryption self-test for des_ecb passed.

Program exited normally.
(gdb) run -T -m des_ecb -D -d .
warning: cannot close "shared object read from target memory": File in wrong format
Starting program: /home/rrelyea/builds/nsstip/mozilla/dist/Linux2.6_x86_glibc_PTH_DBG.OBJ/bin/bltest -T -m des_ecb -D -d .
Reading symbols from shared object read from target memory...done.
Loaded system supplied DSO at 0xf88000
[Thread debugging using libthread_db enabled]
[New Thread -1208236352 (LWP 22026)]
Detaching after fork from child process 22050.
[Switching to Thread -1208236352 (LWP 22026)]

Breakpoint 3, DES_Decrypt (cx=0x887bd70, output=0x887acf8 "",
    outputLen=0xbf8d497c, maxOutputLen=8, input=0x887ace8 "ݳh[<▒\210W",
    inputLen=8) at loader.c:641
641       if (!vector && PR_SUCCESS != freebl_RunLoaderOnce())
(gdb) cont
Continuing.
Decryption self-test for des_ecb passed.

Program exited normally.
(gdb) run -T -m des_cbc -E -d .
warning: cannot close "shared object read from target memory": File in wrong format
Starting program: /home/rrelyea/builds/nsstip/mozilla/dist/Linux2.6_x86_glibc_PTH_DBG.OBJ/bin/bltest -T -m des_cbc -E -d .
Reading symbols from shared object read from target memory...done.
Loaded system supplied DSO at 0x987000
[Thread debugging using libthread_db enabled]
[New Thread -1208387904 (LWP 22053)]
Detaching after fork from child process 22077.
[Switching to Thread -1208387904 (LWP 22053)]

Breakpoint 2, DES_Encrypt (cx=0x9aa0db0, output=0x9a9fd00 "",
    outputLen=0xbfeade8c, maxOutputLen=8, input=0x9a9fcf0 "Mozilla!",
    inputLen=8) at loader.c:630
630       if (!vector && PR_SUCCESS != freebl_RunLoaderOnce())
(gdb) cont
Continuing.
Encryption self-test for des_cbc passed.

Program exited normally.
(gdb) run -T -m des_cbc -D -d .
warning: cannot close "shared object read from target memory": File in wrong format
Starting program: /home/rrelyea/builds/nsstip/mozilla/dist/Linux2.6_x86_glibc_PTH_DBG.OBJ/bin/bltest -T -m des_cbc -D -d .
Reading symbols from shared object read from target memory...done.
Loaded system supplied DSO at 0xb7f000
[Thread debugging using libthread_db enabled]
[New Thread -1208428864 (LWP 22082)]
Detaching after fork from child process 22106.
[Switching to Thread -1208428864 (LWP 22082)]

Breakpoint 3, DES_Decrypt (cx=0x8daadb0, output=0x8da9d00 "",
    outputLen=0xbfba36dc, maxOutputLen=8, input=0x8da9cf0 "=▒▒\203▒La\016",
    inputLen=8) at loader.c:641
641       if (!vector && PR_SUCCESS != freebl_RunLoaderOnce())
(gdb) cont
Continuing.
Decryption self-test for des_cbc passed.

Program exited normally.
(gdb) run -T -m des3_ecb -E -d .
warning: cannot close "shared object read from target memory": File in wrong format
Starting program: /home/rrelyea/builds/nsstip/mozilla/dist/Linux2.6_x86_glibc_PTH_DBG.OBJ/bin/bltest -T -m des3_ecb -E -d .
Reading symbols from shared object read from target memory...done.
Loaded system supplied DSO at 0x4b6000
[Thread debugging using libthread_db enabled]
[New Thread -1209080128 (LWP 22117)]
Detaching after fork from child process 22141.
[Switching to Thread -1209080128 (LWP 22117)]

Breakpoint 2, DES_Encrypt (cx=0x9349d90, output=0x9348d08 "",
    outputLen=0xbfe067ec, maxOutputLen=8, input=0x9348cf8 "Mozilla!",
    inputLen=8) at loader.c:630
630       if (!vector && PR_SUCCESS != freebl_RunLoaderOnce())
(gdb) cont
Continuing.
Encryption self-test for des3_ecb passed.

Program exited normally.
(gdb) run -T -m des3_ecb -D -d .
warning: cannot close "shared object read from target memory": File in wrong format
Starting program: /home/rrelyea/builds/nsstip/mozilla/dist/Linux2.6_x86_glibc_PTH_DBG.OBJ/bin/bltest -T -m des3_ecb -D -d .
Reading symbols from shared object read from target memory...done.
Loaded system supplied DSO at 0xc14000
[Thread debugging using libthread_db enabled]
[New Thread -1208244544 (LWP 22144)]
Detaching after fork from child process 22168.
[Switching to Thread -1208244544 (LWP 22144)]

Breakpoint 3, DES_Decrypt (cx=0x837dd90, output=0x837cd08 "",
    outputLen=0xbfdd2cac, maxOutputLen=8, input=0x837ccf8 "F\a$T▒xA▒",
    inputLen=8) at loader.c:641
641       if (!vector && PR_SUCCESS != freebl_RunLoaderOnce())
(gdb) cont
Continuing.
Decryption self-test for des3_ecb passed.

Program exited normally.

Comment 9

[Robert Relyea]

OK, I think I see the problem. Around line 667 of des.c (from the traceback), we have the following code:
    if (((ptrdiff_t)inbuf & 0x03) == 0) {
#if defined(IS_LITTLE_ENDIAN)
        BYTESWAP(left, temp);
        BYTESWAP(right, temp);
#endif
        HALFPTR(outbuf)[0]  = left;
        HALFPTR(outbuf)[1]  = right;  /**** line 667 ****/
    } else {
        outbuf[0] = (BYTE)(left >> 24);
        outbuf[1] = (BYTE)(left >> 16);
        outbuf[2] = (BYTE)(left >>  8);
        outbuf[3] = (BYTE)(left      );

        outbuf[4] = (BYTE)(right >> 24);
        outbuf[5] = (BYTE)(right >> 16);
        outbuf[6] = (BYTE)(right >>  8);
        outbuf[7] = (BYTE)(right      );
    }


I believe the if statement should be checking the alignment of outbuf rather
than inbuf.

alexi, see if that change fixes the problem.

bob

Comment 10

[Nelson Bolyard (seldom reads bugmail)]

(In reply to comment #9)
> OK, I think I see the problem. Around line 667 of des.c 
Yes, I think that's it, too.  The first bug found in that file.

BTW, bltest does have an offset check, but IIRC it's enabled
from the command line.  I'd say our "all.sh" script doesn't 
do that test.  :-/  

Comment 11

[Alexei Volkov]

Attachment: bug fix

patches if statement to check for outbuf misalignment instead of inbuf.

Comment 12

[Nelson Bolyard (seldom reads bugmail)]

Comment on attachment 216579 [details] [diff] [review]
bug fix

sr=nelson
I'm still amazed we never hit this before now!

Comment 13

[Julien Pierre]

I'd say this bug shouldn't be closed until we have a proper reproducible regression test for the unaligned case checked in . bltest has a function called misalignBuffer . It is called from blapi_selftest() and from main() . But it takes offsets as arguments - input and output offsets, which are set with the -1 and -2 command-line options respectively. I would suggest trying offsets of 0 to 7 for both. Alexei, could you please provide a patch to cipher.sh that does that ?

Comment 14

[Alexei Volkov]

Attachment: cipher.sh patch

the patch will alter cipher.sh to run bltest in the loop testing for various mem misalignment of input and output buffers. Result is reported as a single pass or failure. All failed in/out buff alignment offset pairs will be reported in case of failure.

Comment 15

[Alexei Volkov]

the new cipher.sh script finds no errors if the patch https://bugzilla.mozilla.org/attachment.cgi?id=216579 is applied and fails on des algorithm otherwise. 

Comment 16

[Nelson Bolyard (seldom reads bugmail)]

(In reply to comment #15)
> the new cipher.sh script finds no errors if the patch
> https://bugzilla.mozilla.org/attachment.cgi?id=216579 
> is applied and fails on des algorithm otherwise. 

Please attach to this bug an output log showing the results of 
such a failure.  This will assist my review.  Thanks.

Comment 17

[Julien Pierre]

Nelson,

Here is what's shown as part of output.log in the failure case :

cipher.sh: DES ECB Encrypt (Failed in/out offset pairs:  [0:1][0:2][0:3][0:5][0:6][0:7][4:1][4:2][4:3][4:5][4:6][4:7]) FAILED
cipher.sh: DES ECB Decrypt (Failed in/out offset pairs:  [0:1][0:2][0:3][0:5][0:6][0:7][4:1][4:2][4:3][4:5][4:6][4:7]) FAILED
cipher.sh: DES3 ECB Encrypt (Failed in/out offset pairs:  [0:1][0:2][0:3][0:5][0:6][0:7][4:1][4:2][4:3][4:5][4:6][4:7]) FAILED
cipher.sh: DES3 ECB Decrypt (Failed in/out offset pairs:  [0:1][0:2][0:3][0:5][0:6][0:7][4:1][4:2][4:3][4:5][4:6][4:7]) FAILED

Comment 18

[Nelson Bolyard (seldom reads bugmail)]

Comment on attachment 216586 [details] [diff] [review]
cipher.sh patch

>+          if [ "$failedStr" ]; then

I think this should read

>+          if [ -n "$failedStr" ]; then

sr=nelson when that fix is made

Comment 19

[Alexei Volkov]

test command argument is changed to '-n "$failedStr"'. &#10;&#10;-------------------------------------------------------&#10;&#10;/cvsroot/mozilla/security/nss/lib/freebl/des.c,v  <--  des.c&#10;new revision: 1.5; previous revision: 1.4&#10;done&#10;Checking in tests/cipher/cipher.sh;&#10;/cvsroot/mozilla/security/nss/tests/cipher/cipher.sh,v  <--  cipher.sh&#10;new revision: 1.10; previous revision: 1.9&#10;done&#10;

Comment 20

[Alexei Volkov]

Check into branch&#10;&#10;Checking in lib/freebl/des.c;&#10;/cvsroot/mozilla/security/nss/lib/freebl/des.c,v  <--  des.c&#10;new revision: 1.4.28.1; previous revision: 1.4&#10;done&#10;Checking in tests/cipher/cipher.sh;&#10;/cvsroot/mozilla/security/nss/tests/cipher/cipher.sh,v  <--  cipher.sh&#10;new revision: 1.9.10.1; previous revision: 1.9&#10;done&#10;

Comment 21

[Nelson Bolyard (seldom reads bugmail)]

Alexei, there is something wrong with your comments 19 and 20 above in this bug.
It has something to do with character sets.  Please use an ASCII character set
for those checkins comments, so that all the control characters will not get
changed into strings like this one:
    & # 1 0 ;

Comment 22

[Nelson Bolyard (seldom reads bugmail)]

This fix has been checked in on trunk and branch.
Do any FIPS algorithm tests need to be respun?

Comment 23

[Wan-Teh Chang]

Yes, the FIPS Triple DES algorithm test needs to be
rerun on all platforms.

Comment 24

[Wan-Teh Chang]

Re-doing the FIPS Triple DES algorithm testing may not
be free.  I'm still trying to find out what the extra
charge is.  Is it possible to fix this crash without
changing lib/freebl?

The functions used in FIPS Triple DES algorithm testing
are:
    DES_CreateContext
    DES_Encrypt
    DES_Decrypt
    DES_DestroyContext

This bug can be worked around if outbuf is 8-byte aligned.

Can we intercept a misaligned outbuf in lib/softoken?

Can we work around this bug by aligning outbuf, as Alexei's
patch does?

Either of the above requires turning off the misaligned buffer
testing of bltest in cipher.sh on the NSS_3_11_BRANCH because
bltest uses the same DES_XXX functions in lib/freebl.

Comment 25

[Nelson Bolyard (seldom reads bugmail)]

How much is "not free"?
I oppose introducing a horrid set of kluges into NSS to avoid another review
charge unless it is extremely costly.  
The code was wrong before.  We fixed it.  I'm unwilling to redefine the 
correct semantic behavior of this function to some definition that is 
horribly inconsistent with all other symmetric key functions, just to avoid
this one charge.  
Your time and mine are not free.  If we introduce some horrible new inconsistent definition for this function, then I'm sure we'll pay more in NSS maintennance 
costs in the long run than if we just fix it right now and retest it.  

Comment 26

[Julien Pierre]

Also, intercepting unaligned buffer and dealing with them in softoken might have a runtime performance cost that I don't think our customers should have to pay for.