clean up logging to info and verbose

This commit is contained in:
nganhkhoa 2023-03-06 17:19:09 +07:00
parent 490ce44ccb
commit 7644e834c6
3 changed files with 39 additions and 62 deletions

View File

@ -50,6 +50,7 @@ bytes Connector::finalizeAPDU(int cla, int ins, int p1, int p2, int ne, bytes& d
} }
Connector::Response Connector::sendICC(int cla, int ins, int p1, int p2, int ne, bytes& data) { Connector::Response Connector::sendICC(int cla, int ins, int p1, int p2, int ne, bytes& data) {
#define VERBOSE_LOGGING VERBOSE_LOGGING_ON
LOGI("========================================"); LOGI("========================================");
LOGI("send %02x%02x%02x%02x", cla, ins, p1, p2); LOGI("send %02x%02x%02x%02x", cla, ins, p1, p2);
logBytes(" send data %s", data); logBytes(" send data %s", data);
@ -76,20 +77,14 @@ Connector::Response Connector::sendICC(int cla, int ins, int p1, int p2, int ne,
iso9797_pad(M); iso9797_pad(M);
M.insert(M.end(), dataDO.begin(), dataDO.end()); M.insert(M.end(), dataDO.begin(), dataDO.end());
M.insert(M.end(), do97.begin(), do97.end()); M.insert(M.end(), do97.begin(), do97.end());
logBytes("M %s", M);
bytes N = sm->next_ssc(); bytes N = sm->next_ssc();
N.insert(N.end(), M.begin(), M.end()); N.insert(N.end(), M.begin(), M.end());
iso9797_pad(N); iso9797_pad(N);
logBytes("N %s", N);
bytes CC = sm->mac(N); bytes CC = sm->mac(N);
bytes do8e = sm->do8e(CC); bytes do8e = sm->do8e(CC);
logBytes("CC %s", CC);
logBytes("do8e %s", do8e);
data.clear(); data.clear();
data.insert(data.end(), dataDO.begin(), dataDO.end()); data.insert(data.end(), dataDO.begin(), dataDO.end());
data.insert(data.end(), do97.begin(), do97.end()); data.insert(data.end(), do97.begin(), do97.end());
@ -124,16 +119,11 @@ Connector::Response Connector::sendICC(int cla, int ins, int p1, int p2, int ne,
auto do99 = sm->parseDO99(response.data, DO->size); // this can be null auto do99 = sm->parseDO99(response.data, DO->size); // this can be null
auto do8e = sm->parseDO8E(response.data, DO->size + do99->size); auto do8e = sm->parseDO8E(response.data, DO->size + do99->size);
logBytes("do %s", DO->value);
logBytes("do99 %s", do99->value);
logBytes("do8e %s", do8e->value);
bytes K = sm->next_ssc(); bytes K = sm->next_ssc();
K.insert(K.end(), response.data.begin(), response.data.begin() + DO->size + do99->size); K.insert(K.end(), response.data.begin(), response.data.begin() + DO->size + do99->size);
iso9797_pad(K); iso9797_pad(K);
uint64_t CC = bytes2num(sm->mac(K)); uint64_t CC = bytes2num(sm->mac(K));
LOGI("mac check %llx", CC);
if (CC != bytes2num(do8e->value)) { if (CC != bytes2num(do8e->value)) {
throw "Decoding message failure: different mac"; throw "Decoding message failure: different mac";
@ -153,7 +143,6 @@ Connector::Response Connector::sendICC(int cla, int ins, int p1, int p2, int ne,
if (isPadded) { if (isPadded) {
iso9797_unpad(response.data); iso9797_unpad(response.data);
} }
logBytes("decrypted %s", response.data);
response.success = true; response.success = true;
response.code = (do99->value[0] << 8) | do99->value[1]; response.code = (do99->value[0] << 8) | do99->value[1];
} }
@ -161,6 +150,7 @@ Connector::Response Connector::sendICC(int cla, int ins, int p1, int p2, int ne,
logBytes(" decrypted raw %s", raw_response); logBytes(" decrypted raw %s", raw_response);
logBytes(" decrypted decoded %s", response.data); logBytes(" decrypted decoded %s", response.data);
return response; return response;
#define VERBOSE_LOGGING VERBOSE_LOGGING_OFF
} }
Connector::Response Connector::decodeResponse(bytes& response) { Connector::Response Connector::decodeResponse(bytes& response) {
@ -358,6 +348,7 @@ bytes Connector::readFileBySFI(int sfi) {
} }
bytes Connector::readBinary(size_t offset, size_t length) { bytes Connector::readBinary(size_t offset, size_t length) {
#define VERBOSE_LOGGING VERBOSE_LOGGING_ON
bytes r; bytes r;
const size_t maxToRead = 256; const size_t maxToRead = 256;
@ -383,6 +374,7 @@ bytes Connector::readBinary(size_t offset, size_t length) {
length -= s; length -= s;
} }
return r; return r;
#define VERBOSE_LOGGING VERBOSE_LOGGING_OFF
} }
void Connector::readEFCOM() { void Connector::readEFCOM() {
@ -429,6 +421,9 @@ void Connector::readEFDG15() {
LOGI("FILE DG15 size %d", content.size()); LOGI("FILE DG15 size %d", content.size());
logBytes("FILE DG15 sha256 %s", digest); logBytes("FILE DG15 sha256 %s", digest);
calculatedDigests[15] = digest; calculatedDigests[15] = digest;
// skip 4 dummy bytes
dg15 = bytes(content.begin() + 4, content.end());
} }
typedef struct DigestItem { typedef struct DigestItem {
@ -457,25 +452,6 @@ ASN1_SEQUENCE(EncapsulatedContent) = {
} ASN1_SEQUENCE_END(EncapsulatedContent) } ASN1_SEQUENCE_END(EncapsulatedContent)
IMPLEMENT_ASN1_FUNCTIONS(EncapsulatedContent) IMPLEMENT_ASN1_FUNCTIONS(EncapsulatedContent)
#include <openssl/opensslv.h>
#if OPENSSL_VERSION_NUMBER >= 0x10100000L
typedef struct ECDSA_SIG_st {
BIGNUM *r;
BIGNUM *s;
} ECDSA_SIG;
typedef struct bignum_st
{
BN_ULONG *d; /* Pointer to an array of 'BN_BITS2' bit chunks. */
int top; /* Index of last used d +1. */
/* The next are internal book keeping for bn_expand. */
int dmax; /* Size of the d array. */
int neg; /* one if the number is negative */
int flags;
};
#endif
void Connector::readEFSOD() { void Connector::readEFSOD() {
auto content = readFileBySFI(EFSOD_SFI); auto content = readFileBySFI(EFSOD_SFI);
bytes digest(256 / 8); bytes digest(256 / 8);
@ -531,11 +507,10 @@ void Connector::readEFSOD() {
auto attr = (X509_ATTRIBUTE*)sk_value(attrs, i); auto attr = (X509_ATTRIBUTE*)sk_value(attrs, i);
auto x = X509_ATTRIBUTE_get0_type(attr, 0); auto x = X509_ATTRIBUTE_get0_type(attr, 0);
// LOGI("%d", ASN1_TYPE_get(x)); if (ASN1_TYPE_get(x) == V_ASN1_OCTET_STRING) {
if (ASN1_TYPE_get(x) == 4) {
auto p = x->value.octet_string; auto p = x->value.octet_string;
auto pp = bytes(p->data, p->data + p->length); auto pp = bytes(p->data, p->data + p->length);
logBytes("sod stored message digest %s", pp); logBytes("SOD stored message digest %s", pp);
if (pp != encapsulatedDigest) { if (pp != encapsulatedDigest) {
throw "Encapsulated digest check with attribute data wrong"; throw "Encapsulated digest check with attribute data wrong";
@ -572,6 +547,7 @@ void Connector::readEFSOD() {
BN_bn2hex(ECDSA_SIG_get0_r(cert_sig)), BN_bn2hex(ECDSA_SIG_get0_r(cert_sig)),
BN_bn2hex(ECDSA_SIG_get0_s(cert_sig))); BN_bn2hex(ECDSA_SIG_get0_s(cert_sig)));
// tested personally, <1000 bytes, uncertain
bytes tbs(1000); bytes tbs(1000);
unsigned char* tbsPtr = tbs.data(); unsigned char* tbsPtr = tbs.data();
int tbsSize = i2d_re_X509_tbs(cert, &tbsPtr); int tbsSize = i2d_re_X509_tbs(cert, &tbsPtr);
@ -596,7 +572,7 @@ void Connector::readEFSOD() {
EC_KEY_set_public_key_affine_coordinates(ca, ca_x, ca_y); EC_KEY_set_public_key_affine_coordinates(ca, ca_x, ca_y);
bool ca_verify = ECDSA_do_verify(tbsDigest.data(), tbsDigest.size(), cert_sig, ca); bool ca_verify = ECDSA_do_verify(tbsDigest.data(), tbsDigest.size(), cert_sig, ca);
LOGI("ca verified status %d\n", ca_verify); LOGI("CA verified status %d\n", ca_verify);
if (ca_verify != 1) { if (ca_verify != 1) {
throw "verification with CA returns false"; throw "verification with CA returns false";

View File

@ -178,9 +178,6 @@ bytes des_encrypt(bytes data, uint64_t key) {
r.insert(r.end(), x.begin(), x.end()); r.insert(r.end(), x.begin(), x.end());
cbc = input; cbc = input;
} }
LOGI("des encrypt: %llx", key);
logBytes(" input %s", data);
logBytes(" output %s", r);
return r; return r;
} }
@ -204,9 +201,6 @@ bytes tripledes_cbc_encrypt(bytes data, uint64_t key1, uint64_t key2, uint64_t k
} }
cbc = input; cbc = input;
} }
LOGI("3des encrypt: %llx %llx %llx", key1, key2, key3);
logBytes(" input %s", data);
logBytes(" output %s", r);
return r; return r;
} }
@ -231,9 +225,6 @@ bytes tripledes_cbc_decrypt(bytes data, uint64_t key1, uint64_t key2, uint64_t k
} }
cbc = before_transform; cbc = before_transform;
} }
LOGI("3des decrypt: %llx %llx %llx", key1, key2, key3);
logBytes(" input %s", data);
logBytes(" output %s", r);
return r; return r;
} }

View File

@ -15,8 +15,33 @@
#include <endian.h> #include <endian.h>
#include <android/log.h> #include <android/log.h>
#define LOGTAG "CCCC_LOGGER" #define VERBOSE_LOGGING_ON 1
#define LOGI(...) __android_log_print(ANDROID_LOG_INFO, LOGTAG, __VA_ARGS__) #define VERBOSE_LOGGING_OFF 0
#define VERBOSE_LOGGING VERBOSE_LOGGING_OFF
#define LOGTAG_LOGGER "CCCC_LOGGER"
#define LOGTAG_PROTOCOL "CCCC_PROTOCOL"
#define LOGI(...) \
do {\
if (VERBOSE_LOGGING == VERBOSE_LOGGING_ON) \
__android_log_print(ANDROID_LOG_VERBOSE, LOGTAG_PROTOCOL, __VA_ARGS__); \
else \
__android_log_print(ANDROID_LOG_INFO, LOGTAG_LOGGER, __VA_ARGS__); \
} while (0)
#define logBytes(msg, data) \
do { \
unsigned char charmap[] = {'0', '1', '2', '3', '4', '5', '6', '7', \
'8', '9', 'A', 'B', 'C', 'D', 'E', 'F'}; \
std::string stream; \
for (size_t i = 0; i < (data).size(); i++) { \
stream += charmap[((data)[i] >> 4)]; \
stream += charmap[(data)[i] & 0x0f]; \
} \
LOGI((msg), stream.c_str()); \
} while (0)
typedef std::vector<uint8_t> bytes; typedef std::vector<uint8_t> bytes;
@ -29,26 +54,11 @@ inline bytes randomBytes(size_t length) {
std::numeric_limits<uint8_t>::max()); std::numeric_limits<uint8_t>::max());
static std::default_random_engine generator; static std::default_random_engine generator;
std::vector<uint8_t> data(length); bytes data(length);
std::generate(data.begin(), data.end(), []() { return distribution(generator); }); std::generate(data.begin(), data.end(), []() { return distribution(generator); });
return data; return data;
} }
inline void logBytes(const char* msg, const bytes& data) {
unsigned char charmap[] = {
'0', '1', '2', '3',
'4', '5', '6', '7',
'8', '9', 'A', 'B',
'C', 'D', 'E', 'F'
};
std::string stream;
for (size_t i = 0; i < data.size(); i++) {
stream += charmap[(data[i] >> 4)];
stream += charmap[data[i] & 0x0f];
}
LOGI(msg, stream.c_str());
}
inline uint64_t bytes2num(bytes data) { inline uint64_t bytes2num(bytes data) {
uint64_t num = 0; uint64_t num = 0;
num = std::accumulate(data.begin(), data.end(), num, num = std::accumulate(data.begin(), data.end(), num,