From 1184f21319d6bfda2aa81e4170f9559a86a8fc6e Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Wed, 20 Sep 2017 08:42:54 +0200 Subject: Organize tests into categories ... by adding pytest marks. Signed-off-by: Szczepan Zalega --- unittest/test_pro.py | 62 ++++++++++++++++++++++++++++++++++++++++++------ unittest/test_storage.py | 25 ++++++++++++++++++- 2 files changed, 79 insertions(+), 8 deletions(-) diff --git a/unittest/test_pro.py b/unittest/test_pro.py index 99dcf4d..67fb5a3 100644 --- a/unittest/test_pro.py +++ b/unittest/test_pro.py @@ -5,7 +5,8 @@ from constants import DefaultPasswords, DeviceErrorCode, RFC_SECRET, bb, bbRFC_S from misc import ffi, gs, wait, cast_pointer_to_tuple from misc import is_pro_rtm_07, is_pro_rtm_08, is_storage - +@pytest.mark.lock_device +@pytest.mark.PWS def test_enable_password_safe(C): """ All Password Safe tests depend on AES keys being initialized. They will fail otherwise. @@ -14,7 +15,8 @@ def test_enable_password_safe(C): assert C.NK_enable_password_safe(b'wrong_password') == DeviceErrorCode.WRONG_PASSWORD assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK - +@pytest.mark.lock_device +@pytest.mark.PWS def test_write_password_safe_slot(C): assert C.NK_lock_device() == DeviceErrorCode.STATUS_OK assert C.NK_write_password_safe_slot(0, b'slotname1', b'login1', b'pass1') == DeviceErrorCode.STATUS_NOT_AUTHORIZED @@ -22,6 +24,8 @@ def test_write_password_safe_slot(C): assert C.NK_write_password_safe_slot(0, b'slotname1', b'login1', b'pass1') == DeviceErrorCode.STATUS_OK +@pytest.mark.lock_device +@pytest.mark.PWS @pytest.mark.slowtest def test_write_all_password_safe_slots_and_read_10_times(C): def fill(s, wid): @@ -57,6 +61,8 @@ def test_write_all_password_safe_slots_and_read_10_times(C): assert gs(C.NK_get_password_safe_slot_password(i)) == get_pass(iss) +@pytest.mark.lock_device +@pytest.mark.PWS @pytest.mark.slowtest @pytest.mark.xfail(reason="This test should be run directly after test_write_all_password_safe_slots_and_read_10_times") def test_read_all_password_safe_slots_10_times(C): @@ -88,6 +94,8 @@ def test_read_all_password_safe_slots_10_times(C): assert gs(C.NK_get_password_safe_slot_password(i)) == get_pass(iss) +@pytest.mark.lock_device +@pytest.mark.PWS def test_get_password_safe_slot_name(C): assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK assert C.NK_write_password_safe_slot(0, b'slotname1', b'login1', b'pass1') == DeviceErrorCode.STATUS_OK @@ -100,6 +108,7 @@ def test_get_password_safe_slot_name(C): assert C.NK_get_last_command_status() == DeviceErrorCode.STATUS_OK +@pytest.mark.PWS def test_get_password_safe_slot_login_password(C): assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK assert C.NK_write_password_safe_slot(0, b'slotname1', b'login1', b'pass1') == DeviceErrorCode.STATUS_OK @@ -111,6 +120,7 @@ def test_get_password_safe_slot_login_password(C): assert slot_password == b'pass1' +@pytest.mark.PWS def test_erase_password_safe_slot(C): assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK assert C.NK_erase_password_safe_slot(0) == DeviceErrorCode.STATUS_OK @@ -118,6 +128,7 @@ def test_erase_password_safe_slot(C): assert C.NK_get_last_command_status() == DeviceErrorCode.STATUS_OK # TODO CHECK shouldn't this be DeviceErrorCode.NOT_PROGRAMMED ? +@pytest.mark.PWS def test_password_safe_slot_status(C): C.NK_set_debug(True) assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK @@ -131,7 +142,7 @@ def test_password_safe_slot_status(C): assert is_slot_programmed[1] == 1 -# TODO TOREGISTER +@pytest.mark.aes def test_issue_device_locks_on_second_key_generation_in_sequence(C): if is_pro_rtm_07(C) or is_pro_rtm_08(C): pytest.skip("issue to register: device locks up " @@ -140,6 +151,7 @@ def test_issue_device_locks_on_second_key_generation_in_sequence(C): assert C.NK_build_aes_key(DefaultPasswords.ADMIN) == DeviceErrorCode.STATUS_OK +@pytest.mark.aes def test_regenerate_aes_key(C): C.NK_set_debug(True) assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK @@ -147,7 +159,9 @@ def test_regenerate_aes_key(C): assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK -@pytest.mark.skip +@pytest.mark.lock_device +@pytest.mark.aes +@pytest.mark.factory_reset def test_enable_password_safe_after_factory_reset(C): assert C.NK_lock_device() == DeviceErrorCode.STATUS_OK if is_storage(C): @@ -163,7 +177,8 @@ def test_enable_password_safe_after_factory_reset(C): assert C.NK_build_aes_key(DefaultPasswords.ADMIN) == DeviceErrorCode.STATUS_OK assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK - +@pytest.mark.lock_device +@pytest.mark.aes @pytest.mark.xfail(reason="NK Pro firmware bug: regenerating AES key command not always results in cleared slot data") def test_destroy_password_safe(C): """ @@ -198,6 +213,7 @@ def test_destroy_password_safe(C): assert is_slot_programmed[0] == 0 +@pytest.mark.aes def test_is_AES_supported(C): if is_storage(C): pytest.skip("Storage does not implement this command") @@ -207,6 +223,7 @@ def test_is_AES_supported(C): assert C.NK_get_last_command_status() == DeviceErrorCode.STATUS_OK +@pytest.mark.pin def test_admin_PIN_change(C): new_password = b'123123123' assert C.NK_change_admin_PIN(b'wrong_password', new_password) == DeviceErrorCode.WRONG_PASSWORD @@ -214,6 +231,7 @@ def test_admin_PIN_change(C): assert C.NK_change_admin_PIN(new_password, DefaultPasswords.ADMIN) == DeviceErrorCode.STATUS_OK +@pytest.mark.pin def test_user_PIN_change(C): new_password = b'123123123' assert C.NK_change_user_PIN(b'wrong_password', new_password) == DeviceErrorCode.WRONG_PASSWORD @@ -221,6 +239,8 @@ def test_user_PIN_change(C): assert C.NK_change_user_PIN(new_password, DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK +@pytest.mark.lock_device +@pytest.mark.pin def test_admin_retry_counts(C): default_admin_retry_count = 3 assert C.NK_lock_device() == DeviceErrorCode.STATUS_OK @@ -231,6 +251,8 @@ def test_admin_retry_counts(C): assert C.NK_get_admin_retry_count() == default_admin_retry_count +@pytest.mark.lock_device +@pytest.mark.pin def test_user_retry_counts_change_PIN(C): assert C.NK_change_user_PIN(DefaultPasswords.USER, DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK wrong_password = b'wrong_password' @@ -242,6 +264,9 @@ def test_user_retry_counts_change_PIN(C): assert C.NK_change_user_PIN(DefaultPasswords.USER, DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK assert C.NK_get_user_retry_count() == default_user_retry_count + +@pytest.mark.lock_device +@pytest.mark.pin def test_user_retry_counts_PWSafe(C): default_user_retry_count = 3 assert C.NK_lock_device() == DeviceErrorCode.STATUS_OK @@ -252,6 +277,7 @@ def test_user_retry_counts_PWSafe(C): assert C.NK_get_user_retry_count() == default_user_retry_count +@pytest.mark.pin def test_unlock_user_password(C): C.NK_set_debug(True) default_user_retry_count = 3 @@ -271,16 +297,19 @@ def test_unlock_user_password(C): assert C.NK_get_admin_retry_count() == default_admin_retry_count +@pytest.mark.pin def test_admin_auth(C): assert C.NK_first_authenticate(b'wrong_password', DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.WRONG_PASSWORD assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK +@pytest.mark.pin def test_user_auth(C): assert C.NK_user_authenticate(b'wrong_password', DefaultPasswords.USER_TEMP) == DeviceErrorCode.WRONG_PASSWORD assert C.NK_user_authenticate(DefaultPasswords.USER, DefaultPasswords.USER_TEMP) == DeviceErrorCode.STATUS_OK +@pytest.mark.otp def check_HOTP_RFC_codes(C, func, prep=None, use_8_digits=False): """ # https://tools.ietf.org/html/rfc4226#page-32 @@ -300,6 +329,7 @@ def check_HOTP_RFC_codes(C, func, prep=None, use_8_digits=False): assert bb(code) == r +@pytest.mark.otp @pytest.mark.parametrize("use_8_digits", [False, True, ]) @pytest.mark.parametrize("use_pin_protection", [False, True, ]) def test_HOTP_RFC_use8digits_usepin(C, use_8_digits, use_pin_protection): @@ -315,6 +345,7 @@ def test_HOTP_RFC_use8digits_usepin(C, use_8_digits, use_pin_protection): check_HOTP_RFC_codes(C, lambda x: gs(C.NK_get_hotp_code(x)), use_8_digits=use_8_digits) +@pytest.mark.otp def test_HOTP_token(C): """ Check HOTP routine with written token ID to slot. @@ -333,6 +364,7 @@ def test_HOTP_token(C): assert C.NK_get_last_command_status() == DeviceErrorCode.STATUS_OK +@pytest.mark.otp def test_HOTP_counters(C): """ # https://tools.ietf.org/html/rfc4226#page-32 @@ -357,6 +389,7 @@ def test_HOTP_counters(C): INT32_MAX = 2 ** 31 - 1 +@pytest.mark.otp def test_HOTP_64bit_counter(C): if is_storage(C): pytest.xfail('bug in NK Storage HOTP firmware - counter is set with a 8 digits string, ' @@ -381,6 +414,7 @@ def test_HOTP_64bit_counter(C): assert dev_res == lib_res +@pytest.mark.otp def test_TOTP_64bit_time(C): if is_storage(C): pytest.xfail('bug in NK Storage TOTP firmware') @@ -406,6 +440,7 @@ def test_TOTP_64bit_time(C): assert dev_res == lib_res +@pytest.mark.otp @pytest.mark.xfail(reason="NK Pro: Test fails in 50% of cases due to test vectors set 1 second before interval count change" "Here time is changed on seconds side only and miliseconds part is not being reset apparently" "This results in available time to test of half a second on average, thus 50% failed cases" @@ -454,6 +489,7 @@ def test_TOTP_RFC_usepin(C, PIN_protection): assert data == responses or correct == len(test_data) +@pytest.mark.otp def test_get_slot_names(C): C.NK_set_debug(True) assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK @@ -472,6 +508,7 @@ def test_get_slot_names(C): assert C.NK_get_last_command_status() == DeviceErrorCode.NOT_PROGRAMMED +@pytest.mark.otp def test_get_OTP_codes(C): assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK assert C.NK_write_config(255, 255, 255, False, True, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK @@ -486,6 +523,7 @@ def test_get_OTP_codes(C): assert C.NK_get_last_command_status() == DeviceErrorCode.NOT_PROGRAMMED +@pytest.mark.otp def test_get_OTP_code_from_not_programmed_slot(C): assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK assert C.NK_write_config(255, 255, 255, False, True, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK @@ -503,6 +541,7 @@ def test_get_OTP_code_from_not_programmed_slot(C): assert C.NK_get_last_command_status() == DeviceErrorCode.NOT_PROGRAMMED +@pytest.mark.otp def test_get_code_user_authorize(C): C.NK_set_debug(True) assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK @@ -549,7 +588,8 @@ def test_read_write_config(C): assert config == (255, 255, 255, False, True) -@pytest.mark.skip +@pytest.mark.lock_device +@pytest.mark.factory_reset def test_factory_reset(C): C.NK_set_debug(True) assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK @@ -571,12 +611,13 @@ def test_factory_reset(C): assert C.NK_clear_new_sd_card_warning(DefaultPasswords.ADMIN) == DeviceErrorCode.STATUS_OK +@pytest.mark.status def test_get_status(C): status = C.NK_status() s = gs(status) assert len(s) > 0 - +@pytest.mark.status def test_get_serial_number(C): sn = C.NK_device_serial_number() sn = gs(sn) @@ -584,6 +625,7 @@ def test_get_serial_number(C): print(('Serial number of the device: ', sn)) +@pytest.mark.otp @pytest.mark.parametrize("secret", ['000001', '00'*10+'ff', '00'*19+'ff', '000102', '00'*29+'ff', '00'*39+'ff', '002EF43F51AFA97BA2B46418768123C9E1809A5B' ]) def test_OTP_secret_started_from_null(C, secret): @@ -615,6 +657,7 @@ def test_OTP_secret_started_from_null(C, secret): assert dev_res == lib_res +@pytest.mark.otp @pytest.mark.parametrize("counter", [0, 3, 7, 0xffff, 0xffffffff, 0xffffffffffffffff] ) @@ -647,6 +690,7 @@ def test_HOTP_slots_read_write_counter(C, counter): assert dev_res == lib_res +@pytest.mark.otp @pytest.mark.parametrize("period", [30,60] ) @pytest.mark.parametrize("time", range(21,70,20) ) def test_TOTP_slots_read_write_at_time_period(C, time, period): @@ -677,6 +721,7 @@ def test_TOTP_slots_read_write_at_time_period(C, time, period): assert dev_res == lib_res +@pytest.mark.otp @pytest.mark.parametrize("secret", [RFC_SECRET, 2*RFC_SECRET, '12'*10, '12'*30] ) def test_TOTP_secrets(C, secret): ''' @@ -709,6 +754,7 @@ def test_TOTP_secrets(C, secret): assert dev_res == lib_res +@pytest.mark.otp @pytest.mark.parametrize("secret", [RFC_SECRET, 2*RFC_SECRET, '12'*10, '12'*30] ) def test_HOTP_secrets(C, secret): """ @@ -760,6 +806,7 @@ def test_special_double_press(C): # requires manual check +@pytest.mark.otp def test_edit_OTP_slot(C): """ should change slots counter and name without changing its secret (using null secret for second update) @@ -793,6 +840,7 @@ def test_edit_OTP_slot(C): assert gs(C.NK_get_hotp_slot_name(slot_number)) == changed_name +@pytest.mark.otp @pytest.mark.skip @pytest.mark.parametrize("secret", ['31323334353637383930'*2,'31323334353637383930'*4] ) def test_TOTP_codes_from_nitrokeyapp(secret, C): diff --git a/unittest/test_storage.py b/unittest/test_storage.py index 6671f5b..ec4004f 100644 --- a/unittest/test_storage.py +++ b/unittest/test_storage.py @@ -1,5 +1,4 @@ import pprint - import pytest from conftest import skip_if_device_version_lower_than @@ -22,6 +21,8 @@ def get_dict_from_dissect(status): return d +@pytest.mark.other +@pytest.mark.info def test_get_status_storage(C): skip_if_device_version_lower_than({'S': 43}) status_pointer = C.NK_get_status_storage_as_string() @@ -33,6 +34,8 @@ def test_get_status_storage(C): assert int(status_dict['AdminPwRetryCount']) == default_admin_password_retry_count +@pytest.mark.other +@pytest.mark.info def test_sd_card_usage(C): skip_if_device_version_lower_than({'S': 43}) data_pointer = C.NK_get_SD_usage_data_as_string() @@ -43,12 +46,14 @@ def test_sd_card_usage(C): assert int(data_dict['WriteLevelMax']) <= 100 +@pytest.mark.encrypted def test_encrypted_volume_unlock(C): skip_if_device_version_lower_than({'S': 43}) assert C.NK_lock_device() == DeviceErrorCode.STATUS_OK assert C.NK_unlock_encrypted_volume(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK +@pytest.mark.hidden def test_encrypted_volume_unlock_hidden(C): skip_if_device_version_lower_than({'S': 43}) hidden_volume_password = b'hiddenpassword' @@ -58,6 +63,7 @@ def test_encrypted_volume_unlock_hidden(C): assert C.NK_unlock_hidden_volume(hidden_volume_password) == DeviceErrorCode.STATUS_OK +@pytest.mark.hidden def test_encrypted_volume_setup_multiple_hidden_lock(C): import random skip_if_device_version_lower_than({'S': 45}) #hangs device on lower version @@ -73,6 +79,7 @@ def test_encrypted_volume_setup_multiple_hidden_lock(C): assert C.NK_unlock_hidden_volume(p(i)) == DeviceErrorCode.STATUS_OK +@pytest.mark.hidden @pytest.mark.parametrize("volumes_to_setup", range(1, 5)) def test_encrypted_volume_setup_multiple_hidden_no_lock_device_volumes(C, volumes_to_setup): skip_if_device_version_lower_than({'S': 43}) @@ -92,6 +99,7 @@ def test_encrypted_volume_setup_multiple_hidden_no_lock_device_volumes(C, volume assert C.NK_lock_hidden_volume() == DeviceErrorCode.STATUS_OK +@pytest.mark.hidden @pytest.mark.parametrize("volumes_to_setup", range(1, 5)) def test_encrypted_volume_setup_multiple_hidden_no_lock_device_volumes_unlock_at_once(C, volumes_to_setup): skip_if_device_version_lower_than({'S': 43}) @@ -113,6 +121,7 @@ def test_encrypted_volume_setup_multiple_hidden_no_lock_device_volumes_unlock_at assert C.NK_lock_hidden_volume() == DeviceErrorCode.STATUS_OK +@pytest.mark.hidden @pytest.mark.parametrize("use_slot", range(4)) def test_encrypted_volume_setup_one_hidden_no_lock_device_slot(C, use_slot): skip_if_device_version_lower_than({'S': 43}) @@ -134,6 +143,8 @@ def test_encrypted_volume_setup_one_hidden_no_lock_device_slot(C, use_slot): assert C.NK_lock_hidden_volume() == DeviceErrorCode.STATUS_OK +@pytest.mark.hidden +@pytest.mark.PWS def test_password_safe_slot_name_corruption(C): skip_if_device_version_lower_than({'S': 43}) volumes_to_setup = 4 @@ -204,6 +215,8 @@ def test_password_safe_slot_name_corruption(C): check_volumes_correctness(C) check_PWS_correctness(C) + +@pytest.mark.hidden def test_hidden_volume_corruption(C): # bug: this should return error without unlocking encrypted volume each hidden volume lock, but it does not assert C.NK_lock_encrypted_volume() == DeviceErrorCode.STATUS_OK @@ -216,28 +229,34 @@ def test_hidden_volume_corruption(C): wait(2) assert C.NK_lock_hidden_volume() == DeviceErrorCode.STATUS_OK + +@pytest.mark.unencrypted def test_unencrypted_volume_set_read_only(C): skip_if_device_version_lower_than({'S': 43}) assert C.NK_lock_device() == DeviceErrorCode.STATUS_OK assert C.NK_set_unencrypted_read_only(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK +@pytest.mark.unencrypted def test_unencrypted_volume_set_read_write(C): skip_if_device_version_lower_than({'S': 43}) assert C.NK_lock_device() == DeviceErrorCode.STATUS_OK assert C.NK_set_unencrypted_read_write(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK +@pytest.mark.other def test_export_firmware(C): skip_if_device_version_lower_than({'S': 43}) assert C.NK_export_firmware(DefaultPasswords.ADMIN) == DeviceErrorCode.STATUS_OK +@pytest.mark.other def test_clear_new_sd_card_notification(C): skip_if_device_version_lower_than({'S': 43}) assert C.NK_clear_new_sd_card_warning(DefaultPasswords.ADMIN) == DeviceErrorCode.STATUS_OK +@pytest.mark.encrypted @pytest.mark.slowtest @pytest.mark.skip(reason='long test (about 1h)') def test_fill_SD_card(C): @@ -252,6 +271,8 @@ def test_fill_SD_card(C): wait(5) +@pytest.mark.other +@pytest.mark.info def test_get_busy_progress_on_idle(C): skip_if_device_version_lower_than({'S': 43}) value = C.NK_get_progress_bar_value() @@ -259,6 +280,7 @@ def test_get_busy_progress_on_idle(C): assert C.NK_get_last_command_status() == DeviceErrorCode.STATUS_OK +@pytest.mark.update def test_change_update_password(C): skip_if_device_version_lower_than({'S': 43}) wrong_password = b'aaaaaaaaaaa' @@ -267,6 +289,7 @@ def test_change_update_password(C): assert C.NK_change_update_password(DefaultPasswords.UPDATE_TEMP, DefaultPasswords.UPDATE) == DeviceErrorCode.STATUS_OK +@pytest.mark.other def test_send_startup(C): skip_if_device_version_lower_than({'S': 43}) time_seconds_from_epoch = 0 # FIXME set proper date -- cgit v1.2.1 From 2ea2883145b2ad06d437d3fcf06026583109791a Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 3 Oct 2017 19:23:49 +0200 Subject: Remove libnitrokey-log and add a switch to choose version instead Signed-off-by: Szczepan Zalega --- CMakeLists.txt | 22 +++++++++++----------- unittest/conftest.py | 4 +--- 2 files changed, 12 insertions(+), 14 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 11882f9..6e5ed53 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -83,18 +83,15 @@ ENDIF() IF (NOT LIBNITROKEY_STATIC) add_library(nitrokey SHARED ${SOURCE_FILES}) - add_library(nitrokey-log SHARED ${SOURCE_FILES}) install (TARGETS nitrokey DESTINATION "lib") SET(LIBNAME nitrokey) ELSE() add_library(nitrokey-static STATIC ${SOURCE_FILES}) - add_library(nitrokey-static-log STATIC ${SOURCE_FILES}) SET(LIBNAME nitrokey-static) ENDIF() target_link_libraries(${LIBNAME} hidapi-libusb) -target_link_libraries(${LIBNAME}-log hidapi-libusb) OPTION(ERROR_ON_WARNING "Stop compilation on warning found (not supported for MSVC)" ON) if (NOT MSVC) @@ -104,10 +101,13 @@ if (NOT MSVC) set(COMPILE_FLAGS "${COMPILE_FLAGS} -Werror") endif() ENDIF() - SET_TARGET_PROPERTIES(${LIBNAME} ${LIBNAME}-log PROPERTIES COMPILE_FLAGS ${COMPILE_FLAGS} ) + SET_TARGET_PROPERTIES(${LIBNAME} PROPERTIES COMPILE_FLAGS ${COMPILE_FLAGS} ) endif() -SET_TARGET_PROPERTIES(${LIBNAME} PROPERTIES COMPILE_DEFINITIONS "NO_LOG") +OPTION(NO_LOG "Compile without logging functionality and its strings (decreases size)" OFF) +IF (NO_LOG) + SET_TARGET_PROPERTIES(${LIBNAME} PROPERTIES COMPILE_DEFINITIONS "NO_LOG") +ENDIF() file(GLOB LIB_INCLUDES "include/libnitrokey/*.h") @@ -119,22 +119,22 @@ IF (COMPILE_TESTS) add_library(catch STATIC unittest/catch_main.cpp ) add_executable (test_C_API unittest/test_C_API.cpp) - target_link_libraries (test_C_API ${EXTRA_LIBS} ${LIBNAME}-log catch) + target_link_libraries (test_C_API ${EXTRA_LIBS} ${LIBNAME} catch) add_executable (test2 unittest/test2.cc) - target_link_libraries (test2 ${EXTRA_LIBS} ${LIBNAME}-log catch) + target_link_libraries (test2 ${EXTRA_LIBS} ${LIBNAME} catch) add_executable (test3 unittest/test3.cc) - target_link_libraries (test3 ${EXTRA_LIBS} ${LIBNAME}-log catch) + target_link_libraries (test3 ${EXTRA_LIBS} ${LIBNAME} catch) add_executable (test_HOTP unittest/test_HOTP.cc) - target_link_libraries (test_HOTP ${EXTRA_LIBS} ${LIBNAME}-log catch) + target_link_libraries (test_HOTP ${EXTRA_LIBS} ${LIBNAME} catch) add_executable (test1 unittest/test.cc) - target_link_libraries (test1 ${EXTRA_LIBS} ${LIBNAME}-log catch) + target_link_libraries (test1 ${EXTRA_LIBS} ${LIBNAME} catch) add_executable (test_issues unittest/test_issues.cc) - target_link_libraries (test_issues ${EXTRA_LIBS} ${LIBNAME}-log catch) + target_link_libraries (test_issues ${EXTRA_LIBS} ${LIBNAME} catch) #run with 'make test' or 'ctest' #needs connected PRO device for success diff --git a/unittest/conftest.py b/unittest/conftest.py index 04e85ff..8c9899c 100644 --- a/unittest/conftest.py +++ b/unittest/conftest.py @@ -33,11 +33,9 @@ def C(request): import os, sys path_build = os.path.join("..", "build") paths = [ - os.path.join(path_build,"libnitrokey-log.so"), os.path.join(path_build,"libnitrokey.so"), - os.path.join(path_build,"libnitrokey-log.dll"), + os.path.join(path_build,"libnitrokey.dylib"), os.path.join(path_build,"libnitrokey.dll"), - os.path.join(path_build,"nitrokey-log.dll"), os.path.join(path_build,"nitrokey.dll"), ] for p in paths: -- cgit v1.2.1 From 328eb15d5a1bd170ac44b3daa612e80909311615 Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Wed, 4 Oct 2017 18:01:34 +0200 Subject: Move library unit tests to Python3 Signed-off-by: Szczepan Zalega --- unittest/test_library.py | 32 +++++++++++++++++--------------- 1 file changed, 17 insertions(+), 15 deletions(-) diff --git a/unittest/test_library.py b/unittest/test_library.py index b24c72a..7012619 100644 --- a/unittest/test_library.py +++ b/unittest/test_library.py @@ -1,12 +1,12 @@ import pytest from misc import ffi, gs, to_hex, is_pro_rtm_07, is_long_OTP_secret_handled -from constants import DefaultPasswords, DeviceErrorCode, RFC_SECRET, LibraryErrors +from constants import DefaultPasswords, DeviceErrorCode, RFC_SECRET, LibraryErrors, bbRFC_SECRET def test_too_long_strings(C): - new_password = '123123123' - long_string = 'a' * 100 + new_password = b'123123123' + long_string = b'a' * 100 assert C.NK_change_user_PIN(long_string, new_password) == LibraryErrors.TOO_LONG_STRING assert C.NK_change_user_PIN(new_password, long_string) == LibraryErrors.TOO_LONG_STRING assert C.NK_change_admin_PIN(long_string, new_password) == LibraryErrors.TOO_LONG_STRING @@ -14,26 +14,26 @@ def test_too_long_strings(C): assert C.NK_first_authenticate(long_string, DefaultPasswords.ADMIN_TEMP) == LibraryErrors.TOO_LONG_STRING assert C.NK_erase_totp_slot(0, long_string) == LibraryErrors.TOO_LONG_STRING digits = False - assert C.NK_write_hotp_slot(1, long_string, RFC_SECRET, 0, digits, False, False, "", + assert C.NK_write_hotp_slot(1, long_string, bbRFC_SECRET, 0, digits, False, False, b"", DefaultPasswords.ADMIN_TEMP) == LibraryErrors.TOO_LONG_STRING - assert C.NK_write_hotp_slot(1, 'long_test', RFC_SECRET, 0, digits, False, False, "", + assert C.NK_write_hotp_slot(1, b'long_test', bbRFC_SECRET, 0, digits, False, False, b"", long_string) == LibraryErrors.TOO_LONG_STRING - assert C.NK_get_hotp_code_PIN(0, long_string) == 0 + assert gs(C.NK_get_hotp_code_PIN(0, long_string)) == b"" assert C.NK_get_last_command_status() == LibraryErrors.TOO_LONG_STRING def test_invalid_slot(C): invalid_slot = 255 - assert C.NK_erase_totp_slot(invalid_slot, 'some password') == LibraryErrors.INVALID_SLOT - assert C.NK_write_hotp_slot(invalid_slot, 'long_test', RFC_SECRET, 0, False, False, False, "", - 'aaa') == LibraryErrors.INVALID_SLOT - assert C.NK_get_hotp_code_PIN(invalid_slot, 'some password') == 0 + assert C.NK_erase_totp_slot(invalid_slot, b'some password') == LibraryErrors.INVALID_SLOT + assert C.NK_write_hotp_slot(invalid_slot, b'long_test', bbRFC_SECRET, 0, False, False, False, b"", + b'aaa') == LibraryErrors.INVALID_SLOT + assert gs(C.NK_get_hotp_code_PIN(invalid_slot, b'some password')) == b"" assert C.NK_get_last_command_status() == LibraryErrors.INVALID_SLOT assert C.NK_erase_password_safe_slot(invalid_slot) == LibraryErrors.INVALID_SLOT assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK - assert gs(C.NK_get_password_safe_slot_name(invalid_slot)) == '' + assert gs(C.NK_get_password_safe_slot_name(invalid_slot)) == b'' assert C.NK_get_last_command_status() == LibraryErrors.INVALID_SLOT - assert gs(C.NK_get_password_safe_slot_login(invalid_slot)) == '' + assert gs(C.NK_get_password_safe_slot_login(invalid_slot)) == b'' assert C.NK_get_last_command_status() == LibraryErrors.INVALID_SLOT @@ -44,17 +44,19 @@ def test_invalid_secret_hex_string_for_OTP_write(C, invalid_hex_string): Tests for invalid secret hex string during writing to OTP slot. Invalid strings are not hexadecimal number, empty or longer than 255 characters. """ + invalid_hex_string = invalid_hex_string.encode('ascii') assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK - assert C.NK_write_hotp_slot(1, 'slot_name', invalid_hex_string, 0, True, False, False, '', + assert C.NK_write_hotp_slot(1, b'slot_name', invalid_hex_string, 0, True, False, False, b'', DefaultPasswords.ADMIN_TEMP) == LibraryErrors.INVALID_HEX_STRING - assert C.NK_write_totp_slot(1, 'python_test', invalid_hex_string, 30, True, False, False, "", + assert C.NK_write_totp_slot(1, b'python_test', invalid_hex_string, 30, True, False, False, b"", DefaultPasswords.ADMIN_TEMP) == LibraryErrors.INVALID_HEX_STRING def test_warning_binary_bigger_than_secret_buffer(C): invalid_hex_string = to_hex('1234567890') * 3 + invalid_hex_string = invalid_hex_string.encode('ascii') if is_long_OTP_secret_handled(C): invalid_hex_string *= 2 - assert C.NK_write_hotp_slot(1, 'slot_name', invalid_hex_string, 0, True, False, False, '', + assert C.NK_write_hotp_slot(1, b'slot_name', invalid_hex_string, 0, True, False, False, b'', DefaultPasswords.ADMIN_TEMP) == LibraryErrors.TARGET_BUFFER_SIZE_SMALLER_THAN_SOURCE -- cgit v1.2.1 From b084e6b1e47a11a1c71cf686ccdc35b08b4e17b4 Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Wed, 4 Oct 2017 18:36:50 +0200 Subject: Make sure hidden volumes are created before unlocking them Signed-off-by: Szczepan Zalega --- unittest/test_storage.py | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/unittest/test_storage.py b/unittest/test_storage.py index ec4004f..2466779 100644 --- a/unittest/test_storage.py +++ b/unittest/test_storage.py @@ -219,11 +219,19 @@ def test_password_safe_slot_name_corruption(C): @pytest.mark.hidden def test_hidden_volume_corruption(C): # bug: this should return error without unlocking encrypted volume each hidden volume lock, but it does not - assert C.NK_lock_encrypted_volume() == DeviceErrorCode.STATUS_OK - assert C.NK_unlock_encrypted_volume(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK + skip_if_device_version_lower_than({'S': 43}) hidden_volume_password = b'hiddenpassword' p = lambda i: hidden_volume_password + bb(str(i)) - for i in range(4): + volumes_to_setup = 4 + for i in range(volumes_to_setup): + assert C.NK_create_hidden_volume(i, 20 + i * 10, 20 + i * 10 + i + 1, p(i)) == DeviceErrorCode.STATUS_OK + assert C.NK_unlock_hidden_volume(p(i)) == DeviceErrorCode.STATUS_OK + assert C.NK_lock_hidden_volume() == DeviceErrorCode.STATUS_OK + + assert C.NK_lock_encrypted_volume() == DeviceErrorCode.STATUS_OK + + assert C.NK_unlock_encrypted_volume(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK + for i in range(volumes_to_setup): assert C.NK_unlock_encrypted_volume(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK assert C.NK_unlock_hidden_volume(p(i)) == DeviceErrorCode.STATUS_OK wait(2) -- cgit v1.2.1 From 660a0b6e2d077448b92f4147ca35a9f799daef82 Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Wed, 4 Oct 2017 18:58:04 +0200 Subject: Increase maximum duplicated string length To cover Storage's status string getter Signed-off-by: Szczepan Zalega --- NitrokeyManager.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/NitrokeyManager.cc b/NitrokeyManager.cc index 0d702eb..9ff146d 100644 --- a/NitrokeyManager.cc +++ b/NitrokeyManager.cc @@ -471,7 +471,7 @@ using nitrokey::misc::strcpyT; return get_slot_name(slot_number); } - static const int max_string_field_length = 100; + static const int max_string_field_length = 2*1024; //storage's status string is ~1k const char * NitrokeyManager::get_slot_name(uint8_t slot_number) { auto payload = get_payload(); -- cgit v1.2.1 From 6290c279b4b0d084dfb6a33526fa1263b0d7a2c0 Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Wed, 4 Oct 2017 09:36:09 +0200 Subject: Make additional retries for longer running commands Signed-off-by: Szczepan Zalega --- include/device_proto.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/include/device_proto.h b/include/device_proto.h index bb14b42..cfb7544 100644 --- a/include/device_proto.h +++ b/include/device_proto.h @@ -308,7 +308,7 @@ namespace nitrokey { } if (resp.device_status == static_cast(stick10::device_status::busy)) { dev->m_counters.busy++; - if (busy_counter++<3) { + if (busy_counter++<10) { receiving_retry_counter++; LOG("Status busy, not decreasing receiving_retry_counter counter: " + std::to_string(receiving_retry_counter), Loglevel::DEBUG_L2); -- cgit v1.2.1 From e0284726110bcdcccb6b8fe6c84466cd6c14c612 Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 16:05:34 +0200 Subject: Skip checking packet's CRC Signed-off-by: Szczepan Zalega --- include/device_proto.h | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/include/device_proto.h b/include/device_proto.h index cfb7544..6944bdb 100644 --- a/include/device_proto.h +++ b/include/device_proto.h @@ -298,9 +298,9 @@ namespace nitrokey { }; } - //SENDPASSWORD gives wrong CRC , for now rely on !=0 (TODO report) -// if (resp.device_status == 0 && resp.last_command_crc == outp.crc && resp.isCRCcorrect()) break; - auto CRC_equal_awaited = resp.last_command_crc == outp.crc; + //Some of the commands return wrong CRC, for now skip checking it (TODO list and report) + //if (resp.device_status == 0 && resp.last_command_crc == outp.crc && resp.isCRCcorrect()) break; + auto CRC_equal_awaited = true; // resp.last_command_crc == outp.crc; if (resp.device_status == static_cast(stick10::device_status::ok) && CRC_equal_awaited && resp.isValid()){ successful_communication = true; -- cgit v1.2.1 From 1107681a2a8f53184ef7824fc8947eb88cfabf21 Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 16:05:56 +0200 Subject: Code reformat Signed-off-by: Szczepan Zalega --- include/device_proto.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/include/device_proto.h b/include/device_proto.h index 6944bdb..34c68c3 100644 --- a/include/device_proto.h +++ b/include/device_proto.h @@ -328,8 +328,8 @@ namespace nitrokey { break; } LOG(std::string("Retry status - dev status, awaited cmd crc, correct packet CRC: ") - + std::to_string(resp.device_status) + " " + - std::to_string(CRC_equal_awaited) + + + std::to_string(resp.device_status) + + " " + std::to_string(CRC_equal_awaited) + " " + std::to_string(resp.isCRCcorrect()), Loglevel::DEBUG_L2); if (!resp.isCRCcorrect()) dev->m_counters.wrong_CRC++; -- cgit v1.2.1 From 7ca16405dd827f79b0c9f49f3b44774ce3553a85 Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 15:53:29 +0200 Subject: Number exceptions for easy return code Signed-off-by: Szczepan Zalega --- include/DeviceCommunicationExceptions.h | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/include/DeviceCommunicationExceptions.h b/include/DeviceCommunicationExceptions.h index 2913975..4dbd35d 100644 --- a/include/DeviceCommunicationExceptions.h +++ b/include/DeviceCommunicationExceptions.h @@ -6,6 +6,7 @@ #include #include + class DeviceCommunicationException: public std::runtime_error { std::string message; @@ -14,6 +15,7 @@ public: DeviceCommunicationException(std::string _msg): std::runtime_error(_msg), message(_msg){ ++occurred; } + const uint8_t getType() const {return 1;}; // virtual const char* what() const throw() override { // return message.c_str(); // } @@ -24,21 +26,26 @@ public: class DeviceNotConnected: public DeviceCommunicationException { public: DeviceNotConnected(std::string msg) : DeviceCommunicationException(msg){} + const uint8_t getType(){return 2;}; + }; class DeviceSendingFailure: public DeviceCommunicationException { public: DeviceSendingFailure(std::string msg) : DeviceCommunicationException(msg){} + const uint8_t getType(){return 3;}; }; class DeviceReceivingFailure: public DeviceCommunicationException { public: DeviceReceivingFailure(std::string msg) : DeviceCommunicationException(msg){} + const uint8_t getType(){return 4;}; }; class InvalidCRCReceived: public DeviceReceivingFailure { public: InvalidCRCReceived(std::string msg) : DeviceReceivingFailure(msg){} + const uint8_t getType(){return 5;}; }; -- cgit v1.2.1 From 84f8f634584e22a557bf50f077fb15967311908d Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 15:57:20 +0200 Subject: Return exception type when DeviceCommunicationException is encountered Signed-off-by: Szczepan Zalega --- NK_C_API.cc | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/NK_C_API.cc b/NK_C_API.cc index bac11b3..822c95d 100644 --- a/NK_C_API.cc +++ b/NK_C_API.cc @@ -90,10 +90,10 @@ uint8_t get_without_result(T func){ NK_last_command_status = libraryException.exception_id(); } catch (const InvalidCRCReceived &invalidCRCException){ - ;;; + ; } catch (const DeviceCommunicationException &deviceException){ - NK_last_command_status = -1; + NK_last_command_status = 256-deviceException.getType(); } return NK_last_command_status; } -- cgit v1.2.1 From cf7110f02f793c791b7227bf1579eaaa81d3fd30 Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 15:54:43 +0200 Subject: Add DEBUG_L1 level and set it as default for Python tests Signed-off-by: Szczepan Zalega --- NK_C_API.cc | 6 ++++++ NK_C_API.h | 8 +++++++- include/log.h | 1 + log.cc | 2 ++ unittest/conftest.py | 8 ++++++-- 5 files changed, 22 insertions(+), 3 deletions(-) diff --git a/NK_C_API.cc b/NK_C_API.cc index 822c95d..e730bae 100644 --- a/NK_C_API.cc +++ b/NK_C_API.cc @@ -296,6 +296,12 @@ extern "C" { m->set_debug(state); } + + NK_C_API void NK_set_debug_level(const int level) { + auto m = NitrokeyManager::instance(); + m->set_loglevel(level); + } + NK_C_API int NK_totp_set_time(uint64_t time) { auto m = NitrokeyManager::instance(); return get_without_result([&]() { diff --git a/NK_C_API.h b/NK_C_API.h index 18f8d0a..3742b43 100644 --- a/NK_C_API.h +++ b/NK_C_API.h @@ -14,10 +14,16 @@ extern "C" { #endif /** * Set debug level of messages written on stderr - * @param state state=True - all messages, state=False - only errors level + * @param state state=True - most messages, state=False - only errors level */ NK_C_API void NK_set_debug(bool state); + /** + * Set debug level of messages written on stderr + * @param level (int) 0-lowest verbosity, 5-highest verbosity + */ + NK_C_API void NK_set_debug_level(const int level); + /** * Connect to device of given model. Currently library can be connected only to one device at once. * @param device_model char 'S': Nitrokey Storage, 'P': Nitrokey Pro diff --git a/include/log.h b/include/log.h index 80e5097..a97ff25 100644 --- a/include/log.h +++ b/include/log.h @@ -19,6 +19,7 @@ namespace nitrokey { ERROR, WARNING, INFO, + DEBUG_L1, DEBUG, DEBUG_L2 }; diff --git a/log.cc b/log.cc index 7d61a0d..c29b85b 100644 --- a/log.cc +++ b/log.cc @@ -14,6 +14,8 @@ namespace nitrokey { std::string LogHandler::loglevel_to_str(Loglevel lvl) { switch (lvl) { + case Loglevel::DEBUG_L1: + return std::string("DEBUG_L1"); case Loglevel::DEBUG_L2: return std::string("DEBUG_L2"); case Loglevel::DEBUG: diff --git a/unittest/conftest.py b/unittest/conftest.py index 8c9899c..ef4539c 100644 --- a/unittest/conftest.py +++ b/unittest/conftest.py @@ -20,14 +20,17 @@ def C(request): with open(fp, 'r') as f: declarations = f.readlines() + cnt = 0 a = iter(declarations) for declaration in a: if declaration.strip().startswith('NK_C_API'): declaration = declaration.replace('NK_C_API', '').strip() while ';' not in declaration: declaration += (next(a)).strip() - print(declaration) + # print(declaration) ffi.cdef(declaration, override=True) + cnt +=1 + print('Imported {} declarations'.format(cnt)) C = None import os, sys @@ -73,6 +76,7 @@ def C(request): print('Finished') request.addfinalizer(fin) - C.NK_set_debug(True) + # C.NK_set_debug(True) + C.NK_set_debug_level(3) return C -- cgit v1.2.1 From 69fc2ffcd32527c14c792cf4d3e30e4073a8f0fa Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 15:58:56 +0200 Subject: Add DEBUG_L1 log messages Signed-off-by: Szczepan Zalega --- include/device_proto.h | 42 ++++++++++++++++++++++++++++++++++++++---- 1 file changed, 38 insertions(+), 4 deletions(-) diff --git a/include/device_proto.h b/include/device_proto.h index 34c68c3..d7edfe2 100644 --- a/include/device_proto.h +++ b/include/device_proto.h @@ -223,6 +223,7 @@ namespace nitrokey { LOG(__FUNCTION__, Loglevel::DEBUG_L2); if (dev == nullptr){ + LOG(std::string("Throw: Device not initialized"), Loglevel::DEBUG_L1); throw DeviceNotConnected("Device not initialized"); } dev->m_counters.total_comm_runs++; @@ -241,8 +242,13 @@ namespace nitrokey { LOG("-------------------", Loglevel::DEBUG); LOG("Outgoing HID packet:", Loglevel::DEBUG); LOG(static_cast(outp), Loglevel::DEBUG); + LOG(std::string("=> ") + std::string(commandid_to_string(static_cast(outp.command_id))), Loglevel::DEBUG_L1); - if (!outp.isValid()) throw DeviceSendingFailure("Invalid outgoing packet"); + + if (!outp.isValid()) { + LOG(std::string("Throw: Invalid outgoing packet"), Loglevel::DEBUG_L1); + throw DeviceSendingFailure("Invalid outgoing packet"); + } bool successful_communication = false; int receiving_retry_counter = 0; @@ -255,6 +261,7 @@ namespace nitrokey { // LOG("Encountered communication error, disconnecting device", Loglevel::DEBUG_L2); // dev->disconnect(); dev->m_counters.sending_error++; + LOG(std::string("Throw: Device error while sending command "), Loglevel::DEBUG_L1); throw DeviceSendingFailure( std::string("Device error while sending command ") + std::to_string(status)); @@ -267,6 +274,9 @@ namespace nitrokey { int busy_counter = 0; auto retry_timeout = dev->get_retry_timeout(); while (receiving_retry_counter-- > 0) { + LOG(std::string("receiving_retry_counter count: ") + std::to_string(receiving_retry_counter), + Loglevel::DEBUG_L1); + dev->m_counters.recv_executed++; status = dev->recv(&resp); @@ -308,6 +318,13 @@ namespace nitrokey { } if (resp.device_status == static_cast(stick10::device_status::busy)) { dev->m_counters.busy++; + LOG(std::string("Busy retry ") + + std::to_string(resp.storage_status.device_status) + + " " + + std::to_string(retry_timeout.count()) + + " " + + std::to_string(receiving_retry_counter) + , Loglevel::DEBUG_L1); if (busy_counter++<10) { receiving_retry_counter++; LOG("Status busy, not decreasing receiving_retry_counter counter: " + @@ -358,32 +375,49 @@ namespace nitrokey { if (status <= 0) { dev->m_counters.receiving_error++; + LOG(std::string("Throw: Device error while executing command "), Loglevel::DEBUG_L1); throw DeviceReceivingFailure( //FIXME replace with CriticalErrorException std::string("Device error while executing command ") + std::to_string(status)); } + LOG(std::string("<= ") + + std::string( + commandid_to_string(static_cast(resp.command_id)) + + std::string(" ") + + std::to_string(resp.storage_status.device_status) +// + std::to_string( status_translate_command(resp.storage_status.device_status)) + ), Loglevel::DEBUG_L1); + LOG("Incoming HID packet:", Loglevel::DEBUG); LOG(static_cast(resp), Loglevel::DEBUG); LOG(std::string("receiving_retry_counter count: ") + std::to_string(receiving_retry_counter), - Loglevel::DEBUG_L2); + Loglevel::DEBUG_L1); if (resp.device_status == static_cast(stick10::device_status::busy) && static_cast(resp.storage_status.device_status) == stick20::device_status::busy_progressbar){ dev->m_counters.busy_progressbar++; + LOG(std::string("Throw: Long operation in progress exception"), Loglevel::DEBUG_L1); throw LongOperationInProgressException( resp.command_id, resp.device_status, resp.storage_status.progress_bar_value); } - if (!resp.isValid()) throw InvalidCRCReceived("Invalid incoming packet"); - if (receiving_retry_counter <= 0) + if (!resp.isValid()) { + LOG(std::string("Throw: Invalid incoming packet"), Loglevel::DEBUG_L1); + throw InvalidCRCReceived("Invalid incoming packet"); + } + if (receiving_retry_counter <= 0){ + LOG(std::string("Throw: \"Maximum receiving_retry_counter count reached for receiving response from the device!\"" + + std::to_string(receiving_retry_counter)), Loglevel::DEBUG_L1); throw DeviceReceivingFailure( "Maximum receiving_retry_counter count reached for receiving response from the device!"); + } dev->m_counters.communication_successful++; if (resp.last_command_status != static_cast(stick10::command_status::ok)){ dev->m_counters.command_result_not_equal_0_recv++; + LOG(std::string("Throw: CommandFailedException"), Loglevel::DEBUG_L1); throw CommandFailedException(resp.command_id, resp.last_command_status); } -- cgit v1.2.1 From 7168f4a74b1c4b38582186b36b222eee8b72cc5c Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 15:57:56 +0200 Subject: Update device properties Increase device delays Increase retry count Signed-off-by: Szczepan Zalega --- device.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/device.cc b/device.cc index 2fc55c7..8ec05eb 100644 --- a/device.cc +++ b/device.cc @@ -200,7 +200,7 @@ Stick10::Stick10(): Stick20::Stick20(): - Device(0x20a0, 0x4109, DeviceModel::STORAGE, 20ms, 10, 20ms) + Device(0x20a0, 0x4109, DeviceModel::STORAGE, 40ms, 25, 40ms) { setDefaultDelay(); } -- cgit v1.2.1 From a42e922507aa143868194508b976b4fd3ceac3d1 Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 15:59:35 +0200 Subject: Translate properly Storage error on AES decoding fail Signed-off-by: Szczepan Zalega --- include/device_proto.h | 3 +++ 1 file changed, 3 insertions(+) diff --git a/include/device_proto.h b/include/device_proto.h index d7edfe2..0be40f8 100644 --- a/include/device_proto.h +++ b/include/device_proto.h @@ -300,6 +300,9 @@ namespace nitrokey { resp.last_command_status = static_cast(stick10::command_status::wrong_password); resp.device_status = static_cast(stick10::device_status::ok); break; + case stick20::device_status::no_user_password_unlock: + resp.last_command_status = static_cast(stick10::command_status::AES_dec_failed); + resp.device_status = static_cast(stick10::device_status::ok); default: LOG(std::string("Unknown storage device status, cannot translate: ") + std::to_string(resp.storage_status.device_status), Loglevel::DEBUG); -- cgit v1.2.1 From 2198d1b46d8bbfabc6e04b716ca89583044b277e Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 17:12:41 +0200 Subject: Log update Show progress on busy retries as dots (.) Show warning when expected CRC is different than of received response Show busy retry stats only on delay change Signed-off-by: Szczepan Zalega --- include/device_proto.h | 35 +++++++++++++++++++++++------------ log.cc | 7 +++++++ 2 files changed, 30 insertions(+), 12 deletions(-) diff --git a/include/device_proto.h b/include/device_proto.h index 0be40f8..0be9ed1 100644 --- a/include/device_proto.h +++ b/include/device_proto.h @@ -274,9 +274,6 @@ namespace nitrokey { int busy_counter = 0; auto retry_timeout = dev->get_retry_timeout(); while (receiving_retry_counter-- > 0) { - LOG(std::string("receiving_retry_counter count: ") + std::to_string(receiving_retry_counter), - Loglevel::DEBUG_L1); - dev->m_counters.recv_executed++; status = dev->recv(&resp); @@ -321,13 +318,7 @@ namespace nitrokey { } if (resp.device_status == static_cast(stick10::device_status::busy)) { dev->m_counters.busy++; - LOG(std::string("Busy retry ") - + std::to_string(resp.storage_status.device_status) - + " " - + std::to_string(retry_timeout.count()) - + " " - + std::to_string(receiving_retry_counter) - , Loglevel::DEBUG_L1); + if (busy_counter++<10) { receiving_retry_counter++; LOG("Status busy, not decreasing receiving_retry_counter counter: " + @@ -339,6 +330,13 @@ namespace nitrokey { LOG("Status busy, decreasing receiving_retry_counter counter: " + std::to_string(receiving_retry_counter) + ", current delay:" + std::to_string(retry_timeout.count()), Loglevel::DEBUG); + LOG(std::string("Busy retry ") + + std::to_string(resp.storage_status.device_status) + + " " + + std::to_string(retry_timeout.count()) + + " " + + std::to_string(receiving_retry_counter) + , Loglevel::DEBUG_L1); } } if (resp.device_status == static_cast(stick10::device_status::busy) && @@ -362,6 +360,7 @@ namespace nitrokey { LOG("Invalid incoming HID packet:", Loglevel::DEBUG_L2); LOG(static_cast(resp), Loglevel::DEBUG_L2); dev->m_counters.total_retries++; + LOG(".", Loglevel::DEBUG_L1); std::this_thread::sleep_for(retry_timeout); continue; } @@ -371,6 +370,15 @@ namespace nitrokey { Loglevel::DEBUG); } + if(resp.last_command_crc != outp.crc){ + LOG(std::string("Accepting response with CRC other than expected ") + + "Command ID: " + std::to_string(resp.command_id) + " " + + commandid_to_string(static_cast(resp.command_id)) + " " + + "Reported by response and expected: " + std::to_string(resp.last_command_crc) + "!=" + std::to_string(outp.crc), + Loglevel::WARNING + ); + } + dev->set_last_command_status(resp.last_command_status); // FIXME should be handled on device.recv clear_packet(outp); @@ -394,8 +402,11 @@ namespace nitrokey { LOG("Incoming HID packet:", Loglevel::DEBUG); LOG(static_cast(resp), Loglevel::DEBUG); - LOG(std::string("receiving_retry_counter count: ") + std::to_string(receiving_retry_counter), - Loglevel::DEBUG_L1); + if (dev->get_retry_receiving_count() - receiving_retry_counter > 2) { + LOG(std::string("Packet received with receiving_retry_counter count: ") + + std::to_string(receiving_retry_counter), + Loglevel::DEBUG_L1); + } if (resp.device_status == static_cast(stick10::device_status::busy) && static_cast(resp.storage_status.device_status) diff --git a/log.cc b/log.cc index c29b85b..4a929aa 100644 --- a/log.cc +++ b/log.cc @@ -46,14 +46,21 @@ namespace nitrokey { } std::string LogHandler::format_message_to_string(const std::string &str, const Loglevel &lvl) { + static bool last_short = false; + if (str.length() == 1){ + last_short = true; + return str; + } time_t t = time(nullptr); tm tm = *localtime(&t); std::stringstream s; s + << (last_short? "\n" : "") << "[" << std::put_time(&tm, "%c") << "]" << "[" << loglevel_to_str(lvl) << "]\t" << str << std::endl; + last_short = false; return s.str(); } -- cgit v1.2.1 From be675e293fe94a4a6926125a61e67e92e8788d8a Mon Sep 17 00:00:00 2001 From: Szczepan Zalega Date: Tue, 10 Oct 2017 17:47:30 +0200 Subject: Do not set debug level in tests Signed-off-by: Szczepan Zalega --- unittest/test_pro.py | 9 --------- 1 file changed, 9 deletions(-) diff --git a/unittest/test_pro.py b/unittest/test_pro.py index 67fb5a3..830946d 100644 --- a/unittest/test_pro.py +++ b/unittest/test_pro.py @@ -130,7 +130,6 @@ def test_erase_password_safe_slot(C): @pytest.mark.PWS def test_password_safe_slot_status(C): - C.NK_set_debug(True) assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK assert C.NK_erase_password_safe_slot(0) == DeviceErrorCode.STATUS_OK assert C.NK_write_password_safe_slot(1, b'slotname2', b'login2', b'pass2') == DeviceErrorCode.STATUS_OK @@ -153,7 +152,6 @@ def test_issue_device_locks_on_second_key_generation_in_sequence(C): @pytest.mark.aes def test_regenerate_aes_key(C): - C.NK_set_debug(True) assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK assert C.NK_build_aes_key(DefaultPasswords.ADMIN) == DeviceErrorCode.STATUS_OK assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK @@ -185,7 +183,6 @@ def test_destroy_password_safe(C): Sometimes fails on NK Pro - slot name is not cleared ergo key generation has not succeed despite the success result returned from the device """ - C.NK_set_debug(True) assert C.NK_enable_password_safe(DefaultPasswords.USER) == DeviceErrorCode.STATUS_OK # write password safe slot assert C.NK_write_password_safe_slot(0, b'slotname1', b'login1', b'pass1') == DeviceErrorCode.STATUS_OK @@ -279,7 +276,6 @@ def test_user_retry_counts_PWSafe(C): @pytest.mark.pin def test_unlock_user_password(C): - C.NK_set_debug(True) default_user_retry_count = 3 default_admin_retry_count = 3 new_password = b'123123123' @@ -491,7 +487,6 @@ def test_TOTP_RFC_usepin(C, PIN_protection): @pytest.mark.otp def test_get_slot_names(C): - C.NK_set_debug(True) assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK assert C.NK_erase_totp_slot(0, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK # erasing slot invalidates temporary password, so requesting authentication @@ -543,7 +538,6 @@ def test_get_OTP_code_from_not_programmed_slot(C): @pytest.mark.otp def test_get_code_user_authorize(C): - C.NK_set_debug(True) assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK assert C.NK_write_totp_slot(0, b'python_otp_auth', bbRFC_SECRET, 30, True, False, False, b'', DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK @@ -569,8 +563,6 @@ def cast_pointer_to_tuple(obj, typen, len): def test_read_write_config(C): - C.NK_set_debug(True) - # let's set sample config with pin protection and disabled scrolllock assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK assert C.NK_write_config(0, 1, 2, True, False, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK @@ -591,7 +583,6 @@ def test_read_write_config(C): @pytest.mark.lock_device @pytest.mark.factory_reset def test_factory_reset(C): - C.NK_set_debug(True) assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK assert C.NK_write_config(255, 255, 255, False, True, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK assert C.NK_first_authenticate(DefaultPasswords.ADMIN, DefaultPasswords.ADMIN_TEMP) == DeviceErrorCode.STATUS_OK -- cgit v1.2.1