security(logging): fix aes implementation in audit logging

ee/audit/run_ee.go

@@ -107,37 +107,161 @@ func run() error {
 		glog.Info("audit file is empty")
 		return nil
 	}
-	var iterator int64 = 0
 
-	iv := make([]byte, aes.BlockSize)
-	x.Check2(file.ReadAt(iv, iterator))
-	iterator = iterator + aes.BlockSize
+	// decrypt header in audit log to verify encryption key
+	// [16]byte IV + [4]byte len(x.VerificationText) + [11]byte x.VerificationText
+	decryptHeader := func() ([]byte, int64, error) {
+		var iterator int64 = 0
+		iv := make([]byte, aes.BlockSize)
+		_, err := file.ReadAt(iv, iterator) // get first iv
+		if err != nil {
+			return nil, 0, err
+		}
+		iterator = iterator + aes.BlockSize + 4 // length of verification text encoded in uint32
 
-	t := make([]byte, len(x.VerificationText))
-	x.Check2(file.ReadAt(t, iterator))
-	iterator = iterator + int64(len(x.VerificationText))
+		ct := make([]byte, len(x.VerificationText))
+		_, err = file.ReadAt(ct, iterator)
+		if err != nil {
+			return nil, 0, err
+		}
+		iterator = iterator + int64(len(x.VerificationText))
 
-	stream := cipher.NewCTR(block, iv)
-	stream.XORKeyStream(t, t)
-	if string(t) != x.VerificationText {
-		return errors.New("invalid encryption key provided. Please check your encryption key")
+		text := make([]byte, len(x.VerificationText))
+		stream := cipher.NewCTR(block, iv)
+		stream.XORKeyStream(text, ct)
+		if string(text) != x.VerificationText {
+			return nil, 0, errors.New("invalid encryption key provided. Please check your encryption key")
+		}
+		return iv, iterator, nil
 	}
 
-	for {
-		// if its the end of data. finish decrypting
-		if iterator >= stat.Size() {
-			break
+	// [12]byte baseIV + [4]byte len(x.VerificationTextDeprecated) + [11]byte x.VerificationTextDeprecated
+	decryptHeaderDeprecated := func() ([]byte, int64, error) {
+		var iterator int64 = 0
+
+		iv := make([]byte, aes.BlockSize)
+		_, err := file.ReadAt(iv, iterator)
+		if err != nil {
+			return nil, 0, err
 		}
-		x.Check2(file.ReadAt(iv[12:], iterator))
-		iterator = iterator + 4
+		iterator = iterator + aes.BlockSize
 
-		content := make([]byte, binary.BigEndian.Uint32(iv[12:]))
-		x.Check2(file.ReadAt(content, iterator))
-		iterator = iterator + int64(binary.BigEndian.Uint32(iv[12:]))
+		ct := make([]byte, len(x.VerificationTextDeprecated))
+		_, err = file.ReadAt(ct, iterator)
+		if err != nil {
+			return nil, 0, err
+		}
+		iterator = iterator + int64(len(x.VerificationTextDeprecated))
+
+		text := make([]byte, len(x.VerificationTextDeprecated))
 		stream := cipher.NewCTR(block, iv)
-		stream.XORKeyStream(content, content)
-		x.Check2(outfile.Write(content))
+		stream.XORKeyStream(text, ct)
+		if string(text) != x.VerificationTextDeprecated {
+			return nil, 0, errors.New("invalid encryption key provided. Please check your encryption key")
+		}
+		return iv, iterator, nil
 	}
+
+	useDeprecated := false
+	iv, iterator, err := decryptHeader()
+	if err != nil {
+		// might have an old audit log
+		iv2, iterator2, err := decryptHeaderDeprecated()
+		if err != nil {
+			return errors.New("invalid encryption key provided. Please check your encryption key")
+		}
+		// found old audit log
+		useDeprecated = true
+		iv, iterator = iv2, iterator2
+	}
+
+	var count int
+
+	// encrypted writes each have the form below
+	// IV generated for each write
+	// #################################################################
+	// #####   [16]byte IV + [4]byte uint32(len(p)) + [:]byte p    #####
+	// #################################################################
+	decryptBody := func() {
+		for {
+			count++
+			// if its the end of data. finish decrypting
+			if iterator >= stat.Size() {
+				break
+			}
+			n, err := file.ReadAt(iv, iterator)
+			if err != nil {
+				glog.Warningf("received %v while decrypting audit log\n", err)
+				glog.Warningf("read %v bytes, expected %v\n", n, len(iv))
+			}
+			iterator = iterator + 16
+			length := make([]byte, 4)
+			n, err = file.ReadAt(length, iterator)
+			if err != nil {
+				glog.Warningf("received %v while decrypting audit log\n", err)
+				glog.Warningf("read %v bytes, expected %v\n", n, len(length))
+			}
+			iterator = iterator + 4
+
+			content := make([]byte, binary.BigEndian.Uint32(length))
+			n, err = file.ReadAt(content, iterator)
+			if err != nil {
+				glog.Warningf("received %v while decrypting audit log\n", err)
+				glog.Warningf("read %v bytes, expected %v\n", n, len(content))
+			}
+			iterator = iterator + int64(binary.BigEndian.Uint32(length))
+
+			stream := cipher.NewCTR(block, iv)
+			stream.XORKeyStream(content, content)
+			n, err = outfile.Write(content)
+			if err != nil {
+				glog.Warningf("received %v while writing decrypted audit log\n", err)
+				glog.Warningf("wrote %v bytes, expected to write %v\n", n, len(content))
+			}
+		}
+	}
+
+	// encrypted writes in body have the form
+	// baseIV is constant, last 4 bytes vary
+	// ########################################################
+	// #####   [4]byte uint32(len(p)) + [:]byte p         #####
+	// ########################################################
+	decryptBodyDeprecated := func() {
+		for {
+			// if its the end of data. finish decrypting
+			if iterator >= stat.Size() {
+				break
+			}
+			n, err := file.ReadAt(iv[12:], iterator)
+			if err != nil {
+				glog.Warningf("received %v while decrypting audit log\n", err)
+				glog.Warningf("read %v bytes, expected %v\n", n, len(iv[12:]))
+			}
+			iterator = iterator + 4
+
+			content := make([]byte, binary.BigEndian.Uint32(iv[12:]))
+			n, err = file.ReadAt(content, iterator)
+			if err != nil {
+				glog.Warningf("received %v while decrypting audit log\n", err)
+				glog.Warningf("read %v bytes, expected %v\n", n, len(content))
+			}
+			iterator = iterator + int64(binary.BigEndian.Uint32(iv[12:]))
+			stream := cipher.NewCTR(block, iv)
+			stream.XORKeyStream(content, content)
+			n, err = outfile.Write(content)
+			if err != nil {
+				glog.Warningf("received %v while writing decrypted audit log\n", err)
+				glog.Warningf("wrote %v bytes, expected to write %v\n", n, len(content))
+			}
+		}
+	}
+
+	if useDeprecated {
+		decryptBodyDeprecated()
+	} else {
+		decryptBody()
+	}
+
 	glog.Infof("Decryption of Audit file %s is Done. Decrypted file is %s",
 		decryptCmd.Conf.GetString("in"),
 		decryptCmd.Conf.GetString("out"))