Hi,
I'm in the process of reviewing performance of various security tokens
(the Yubikeys, the FST-01, Nitrokey), and I am getting somewhat
interesting (if not surprising) results:
Times are in seconds.
It looks like the Yubikey 4 is the fastest, being (only?) 10 times
slower than the CPU (i3-6100U). That slows down another order of
magnitude with 4096 keys. The NEO is as slow in 2048 as the 4 is in
4096, and of course doesn't support 4096 at all. The FST-01 is the
slowest of the bunch, taking more than a full second to kick decryption
in 2048bit RSA and 8 seconds in 4096 bits.
I'm looking for feedback on the results and the test procedure, which is
a Python script, attached. I'm aware of the limitations of the script,
namely that it treats the *whole* GPG decryption process as a blackbox,
which includes AES and all sorts of stuff. In my tests, GPG chooses
AES-256 which is why I chose a 16 bytes filesize. Since the timings
seems to be fairly consistent, I am assuming the delays are consistent.
Also, I was thinking of removing the file altogether and pipe
pseudo-random bytes in to remove possible disk contention issues, but my
test results are fairly consistent so I don't think that's necessary
either.
I'm also looking at getting my hands on Nitrokey hardware and adding
elleptic curve support to complete the test suite.
Any comments and help would of course be very welcome.
A.
--
Antoine Beaupré
LWN.net
#!/usr/bin/python
'''This script will test decryption performance of GPG, particularly
with smart cards. Note that it will wipe the encryption key of the
smart card you provide it, so it's a dangerous thing to do on a real
card.
Test data can be generated automatically by the script, or by
hand. The grapher expects a CSV file with 3 columns: device, algorithm
and time. The first two are strings, the latter is a float, in
seconds. Note that we count the total runtime of GPG, which yields
lower bandwidth results than what the card is probably capable of
doing.
'''
# To generate the data by hand, use the following procedure:
#
# 1. very important: work in a temporary keyring:
#
# export GNUPGHOME=$PWD/gpgtmp
# mkdir $GNUPGHOME; chmod 700 $GNUPGHOME
#
# 1. create a 100M file of garbage
#
# dd if=/dev/urandom of=testfile bs=1k count=100k
#
# 2. generate a new private keypair:
#
# gpg --batch --generate-key <<EOF
# %transient-key
# %no-protection
# Key-Type: RSA
# Key-Length: 2048
# Key-Usage: sign
# Subkey-Type: RSA
# Subkey-Length: 2048
# Subkey-Usage: encrypt
# Name-Real: test key
# Name-Email: t...@example.com
# Expire-Date: 1w
# EOF
#
# 3. encrypt stuff to the key:
#
# gpg --encrypt -r t...@example.com testfile
#
# 4. benchmark decryption, 101 times (first will prompt for password
# so not relevant):
#
# $ time gpg --quiet --decrypt < testfile.gpg | pv > /dev/null
# 1.08user 0.06system 0:01.16elapsed 98%CPU (0avgtext+0avgdata 5072maxresident)k
# 0inputs+0outputs (0major+265minor)pagefaults 0swaps
# 100MiO 0:00:01 [85,5MiB/s] [ <=> ]
# $ for i in $(seq 100) ; do
# time gpg --quiet --decrypt < testfile.gpg 2>> i3-6100.txt | pv > /dev/null
# done
#
# 5. move key to card:
#
# gpg --edit-key t...@example.com
# key 1
# keytocard
# save
#
# 6. repeat step 4 with the Yubikey NEO:
#
# $ time gpg --quiet --decrypt < testfile.gpg | pv > /dev/null
# 1.12user 0.04system 0:06.76elapsed 17%CPU (0avgtext+0avgdata 4952maxresident)k
# 0inputs+0outputs (0major+264minor)pagefaults 0swaps
# 100MiO 0:00:06 [14,8MiB/s] [ <=> ]
# $ for i in $(seq 100) ; do
# time gpg --quiet --decrypt < testfile.gpg 2>> Yubikey-NEO.txt | pv > /dev/null
# done
# 100MiO 0:00:01 [53,1MiB/s] [ <=> ]
# [...]
#
# 7. repeat step 2-6 with the FST-01:
#
# $ time gpg --quiet --decrypt < testfile.gpg | pv > /dev/null
# 1.14user 0.03system 0:07.03elapsed 16%CPU (0avgtext+0avgdata 4752maxresident)k
# 0inputs+0outputs (0major+258minor)pagefaults 0swaps
# 100MiO 0:00:07 [14,2MiB/s] [ <=> ]
# $ for i in $(seq 100) ; do
# time gpg --quiet --decrypt < testfile.gpg 2>> FST-01.txt | pv > /dev/null
# done
# 100MiO 0:00:02 [41,3MiB/s] [ <=> ]
# [...]
#
# 8. repeat step 2-6 with the Yubikey 4:
#
# $ time gpg --quiet --decrypt < testfile.gpg | pv > /dev/null
# 1.14user 0.04system 0:03.48elapsed 33%CPU (0avgtext+0avgdata 4852maxresident)k
# 0inputs+0outputs (0major+260minor)pagefaults 0swaps
# 100MiO 0:00:03 [28,7MiB/s] [ <=> ]
# $ for i in $(seq 100) ; do
# time gpg --quiet --decrypt < testfile.gpg 2>> Yubikey-4.txt | pv > /dev/null
# done
# 100MiO 0:00:01 [76,1MiB/s] [ <=> ]
# [...]
#
# 8. extract elapsed time:
#
# for f in *.txt ; do
# sed -n "/elapsed/{s/^.* 0:\([0-9]*.[0-9]*\)elapsed.*\$/rsa2048,$(basename $f .txt),\1/;p}" "$f"
# done > results-2048.csv
#
# 9. repeat step 2-7 with 4096 bit keys
#
# 10. merge into the CSV file:
#
# ( echo 'algorithm,device,time' ; cat results-*.csv ) > results.csv
#
# 11. generate the graph:
#
# python histo.py results.csv --output results.png
from __future__ import print_function
from builtins import range, input
import argparse
import datetime
import logging
import os
import psutil
import shutil
import subprocess
import sys
import tempfile
import matplotlib.pyplot as plt
import pandas
import seaborn as sns
class Timer(object):
"""this class is to track time and resources passed
originally from bup-cron, but improved to include memory usage"""
def __init__(self):
"""initialize the timstamp"""
self.stamp = datetime.datetime.now()
def times(self):
"""return a string designing resource usage"""
return 'user %s system %s chlduser %s chldsystem %s' % os.times()[:4]
def rss(self):
process = psutil.Process(os.getpid())
return process.memory_info().rss
def memory(self):
return 'RSS %s' % sizeof_fmt_iec(self.rss())
def diff(self):
"""a datediff between the creation of the object and now"""
return datetime.datetime.now() - self.stamp
def __str__(self):
"""return a string representing the time passed and resources used"""
return 'elasped: %s (%s %s)' % (str(self.diff()),
self.times(),
self.memory())
def sizeof_fmt(num, suffix='B', units=None, power=None,
sep=' ', precision=2, sign=False):
"""format the given size as a human-readable size"""
prefix = '+' if sign and num > 0 else ''
for unit in units[:-1]:
if abs(round(num, precision)) < power:
if isinstance(num, int):
return "{}{}{}{}{}".format(prefix, num, sep, unit, suffix)
else:
return "{}{:3.{}f}{}{}{}".format(prefix, num, precision,
sep, unit, suffix)
num /= float(power)
return "{}{:.{}f}{}{}{}".format(prefix, num, precision,
sep, units[-1], suffix)
def sizeof_fmt_iec(num, suffix='B', sep=' ', precision=2, sign=False):
return sizeof_fmt(num, suffix=suffix, power=1024,
units=['', 'Ki', 'Mi', 'Gi', 'Ti',
'Pi', 'Ei', 'Zi', 'Yi'],
sep=sep, precision=precision, sign=sign)
def load_csv():
logging.info('loading CSV file %s with pandas', args.datafile)
data = pandas.read_csv(args.datafile)
# expected rows format:
# algorithm,device,time
# string,string,float
# convert from time to bandwidth
data['bandwidth'] = args.size / data['time']
return data
def render_graph():
logging.info('rendering graph with seaborn')
ax = sns.barplot(data=data, x='device', y=args.variable, hue='algorithm')
ax.set_title('RSA decryption (%s)' % args.variable)
for p in ax.patches:
ax.annotate(s="%.2f" % p.get_height(),
xy=(p.get_x() + p.get_width() / 2., p.get_height()))
if args.output == sys.stdout and \
('DISPLAY' in os.environ or sys.stdout.isatty()):
logging.info("drawing on tty")
plt.show()
else:
logging.info('drawing to file %s', args.output)
plt.savefig(args.output, bbox_inches='tight')
def setup_home(algo, size):
logging.info('killing gpg-agent so it takes into account our new HOME')
os.system('killall gpg-agent')
os.environ['GNUPGHOME'] = tempfile.mkdtemp(prefix='gpgbench-')
path = os.path.join(os.environ['GNUPGHOME'], 'testfile')
logging.info('writing %s test file in %s',
sizeof_fmt_iec(float(args.size)), path)
timer = Timer()
with open(path, 'wb') as testfile:
testfile.write(os.urandom(args.size))
logging.debug('wrote file in %s', timer)
cmd = '''gpg --quiet --batch --generate-key <<EOF
%%transient-key
%%no-protection
Key-Type: %s
Key-Length: %s
Key-Usage: sign
Subkey-Type: %s
Subkey-Length: %s
Subkey-Usage: encrypt
Name-Real: test key
Name-Email: t...@example.com
Expire-Date: 1w
EOF''' % (algo, size, algo, size)
logging.debug('keygen command: %s', cmd)
logging.info('generating new %s %s key', algo, size)
if not os.system(cmd) == 0:
return False
logging.info('encrypting test file')
try:
os.unlink(os.path.join(os.environ['GNUPGHOME'], 'testfile.gpg'))
except OSError:
pass
return os.system('gpg --quiet --encrypt -r t...@example.com %s'
% os.path.join(os.environ['GNUPGHOME'], 'testfile')) == 0
def delete_home():
logging.info('removing test gpg dir')
shutil.rmtree(os.environ['GNUPGHOME'], ignore_errors=True)
def decrypt_file():
return os.system('gpg --quiet --decrypt < %s > %s'
% (os.path.join(os.environ['GNUPGHOME'], 'testfile.gpg'),
'/dev/null')) == 0
def move_to_keycard():
logging.info('moving private key to keycard')
proc = subprocess.Popen(['gpg', '--status-fd', '2', '--command-fd', '0',
'--batch', '--edit-key', 't...@example.com'],
stdin=subprocess.PIPE,
stdout=subprocess.PIPE,
stderr=subprocess.PIPE)
class GpgDialogError(Exception):
pass
def wait_for_prompt(prompt='[GNUPG:] GET_LINE keyedit.prompt'):
while True:
line = proc.stderr.readline().strip()
logging.debug(line)
if line == prompt:
break
elif line.startswith('[GNUPG:] GET_'):
raise GpgDialogError('unexpected prompt: %s' % line)
success = True
try:
wait_for_prompt()
proc.stdin.write("key 1\n") # select first subkey
logging.debug(proc.stderr.readline()) # [GNUPG:] GOT_IT
wait_for_prompt()
proc.stdin.write("keytocard\n")
logging.debug("sent 'keytocard'")
logging.debug(proc.stderr.readline()) # [GNUPG:] GOT_IT
wait_for_prompt('[GNUPG:] GET_LINE cardedit.genkeys.storekeytype')
proc.stdin.write("2\n") # move to encryption slot
logging.debug("sent 2")
logging.debug(proc.stderr.readline()) # [GNUPG:] GOT_IT
# XXX: known bug: this will only happen if the key is not new
wait_for_prompt('[GNUPG:] GET_BOOL cardedit.genkeys.replace_key')
proc.stdin.write("y\n")
wait_for_prompt()
proc.stdin.write("save\n")
except GpgDialogError as e:
logging.warn('failed to communicate with GPG: %s', e)
success = False
proc.stderr.close()
proc.stdout.close()
proc.stdin.close()
proc.wait()
return success and proc.returncode == 0
def gen_test_data():
logging.info('generating test data')
data = pandas.DataFrame()
keycard_curr = 'CPU'
for keycard in args.keycard:
for algo in ['RSA']:
for size in [2048, 4096]:
algo_size = '%s-%s' % (algo, size)
if not setup_home(algo, size):
logging.warning('failed to setup home %s',
os.environ['GNUPGHOME'])
break
if keycard != 'CPU':
if keycard != keycard_curr:
input("insert keycard %s and press enter to continue: "
% keycard)
keycard_curr = keycard
if not move_to_keycard():
logging.warning('failed to move to keycard')
break
logging.info('first decryption test to remove password prompt')
if not decrypt_file():
logging.warning('failed to decrypt file with keycard %s',
keycard)
break
logging.info('testing decryption, %d iterations',
args.iterations)
for i in range(args.iterations):
timer = Timer()
decrypt_file()
s = timer.diff().total_seconds()
data = data.append([(keycard, algo_size, s)])
print("\rdecryption pass %d [%s]" % (i+1, timer), end='')
sys.stdout.flush()
print()
delete_home()
data.columns = ['device', 'algorithm', 'time']
# convert from time to bandwidth
data['bandwidth'] = args.size / data['time']
logging.debug('generated dataset: %s', data)
if args.save:
logging.info('dataset saved to file %s', args.save)
data.to_csv(args.save)
return data
if __name__ == "__main__":
parser = argparse.ArgumentParser(epilog=__doc__,
description='Benchmark cryptographic tokens')
parser.add_argument('datafile', default=None, nargs='?',
help='CSV file to read instead of running the test)')
parser.add_argument('--verbose', '-v', dest='log_level',
help='show informative messages',
action='store_const', const='INFO', default='WARNING')
parser.add_argument('--debug', '-d', dest='log_level',
help='show debug messages',
action='store_const', const='DEBUG', default='WARNING')
parser.add_argument('--output', '-o', type=argparse.FileType('w'),
default=sys.stdout, nargs='?', metavar='FILE',
help='save graph to FILE or stdout')
parser.add_argument('--save', type=argparse.FileType('w'), metavar='CSV',
help='save generated results to CSV file')
parser.add_argument('--iterations', '-i', metavar='N',
type=int, default=100,
help='repeat the test N times (%(default)s)')
parser.add_argument('--keycard', '-k', nargs='+',
default=['CPU'], metavar='NAME',
help='test keycards NAME in sequence (%(default)s)')
parser.add_argument('--size', '-s', default=16,
metavar='SIZE', type=int,
help='SIZE of sample file, in bytes (%(default)s)')
parser.add_argument('--bandwidth', dest='variable', default='time',
action='store_const', const='bandwidth',
help='plot bandwidth instead of %(default)s')
args = parser.parse_args()
logging.basicConfig(format='%(asctime)s %(message)s', level=args.log_level)
if args.datafile is not None:
data = load_csv()
else:
data = gen_test_data()
render_graph()
_______________________________________________
Gnupg-users mailing list
Gnupg-users@gnupg.org
http://lists.gnupg.org/mailman/listinfo/gnupg-users
