From f06c8dee90dbb6ccf031af872efb2cdd8d3d3b8a Mon Sep 17 00:00:00 2001 From: =?utf8?q?Felix=20D=C3=B6rre?= Date: Tue, 30 Dec 2014 21:52:20 +0100 Subject: [PATCH] add: Add more verbose logging --- src/apps/client.cpp | 66 ++++++++++++++++++++++++++++--------- src/apps/signer.cpp | 2 -- src/database.h | 4 ++- src/mysql.cpp | 22 ++++++++++--- src/mysql.h | 3 +- src/record.cpp | 13 ++++++-- src/record.h | 4 +-- src/recordHandler.cpp | 33 +++++++++++++++---- src/remoteSigner.cpp | 7 ++-- src/remoteSigner.h | 2 ++ src/simpleOpensslSigner.cpp | 15 +++++++-- 11 files changed, 131 insertions(+), 40 deletions(-) diff --git a/src/apps/client.cpp b/src/apps/client.cpp index 8ed2ca4..5741606 100644 --- a/src/apps/client.cpp +++ b/src/apps/client.cpp @@ -81,44 +81,80 @@ int main( int argc, const char* argv[] ) { continue; } + std::ofstream* logP = new std::ofstream( std::string( "logs/" ) + job->id + std::string( "_" ) + job->warning + std::string( ".log" ) ); + std::shared_ptr logPtr( + logP, + []( std::ofstream * ptr ) { + ( *ptr ).close(); + delete ptr; + } ); + std::ofstream& log = *logP; + + sign->setLog( logPtr ); + log << "TASK ID: " << job->id << std::endl; + log << "TRY: " << job->warning << std::endl; + log << "TARGET: " << job->target << std::endl; + log << "TASK: " << job->task << std::endl << std::endl; + if( job->task == "sign" ) { try { std::shared_ptr cert = jp->fetchTBSCert( job ); + log << "INFO: message digest: " << cert->md << std::endl; + log << "INFO: profile id: " << cert->profile << std::endl; + + for( auto& SAN : cert->SANs ) { + log << "INFO: SAN " << SAN->type << ": " << SAN->content; + } + + for( auto& AVA : cert->AVAs ) { + log << "INFO: AVA " << AVA->name << ": " << AVA->value; + } if( !cert ) { std::cout << "wasn't able to load CSR" << std::endl; - return 2; + jp->failJob( job ); + continue; } - std::cout << "Found a CSR at '" << cert->csr << "' signing" << std::endl; + log << "FINE: Found the CSR at '" << cert->csr << "'" << std::endl; cert->csr_content = readFile( cert->csr ); - std::cout << cert->csr_content << " content " << std::endl; + log << "FINE: CSR is " << std::endl << cert->csr_content << std::endl; std::shared_ptr res = sign->sign( cert ); if( !res ) { - std::cout << "Error no cert came back." << std::endl; + log << "ERROR: The signer failed. There was no certificate." << std::endl; + jp->failJob( job ); continue; } - std::cout << "did it!" << res->certificate << std::endl; + log << "FINE: CERTIFICATE LOG: " << res->log << std::endl; + log << "FINE: CERTIFICATE:" << std::endl << res->certificate << std::endl; std::string fn = writeBackFile( atoi( job->target.c_str() ), res->certificate ); res->crt_name = fn; jp->writeBack( job, res ); - std::cout << "wrote back" << std::endl; + log << "FINE: signing done." << std::endl; + + if( DAEMON ) { + jp->finishJob( job ); + } + + continue; } catch( const char* c ) { - std::cerr << "ERROR: " << c << std::endl; - return 2; + log << "ERROR: " << c << std::endl; } catch( std::string c ) { - std::cerr << "ERROR: " << c << std::endl; - return 2; + log << "ERROR: " << c << std::endl; } - } else { - std::cout << "Unknown job type" << job->task << std::endl; - } - if( DAEMON && !jp->finishJob( job ) ) { - return 1; + try { + jp->failJob( job ); + } catch( const char* c ) { + log << "ERROR: " << c << std::endl; + } catch( std::string c ) { + log << "ERROR: " << c << std::endl; + } + } else { + log << "Unknown job type" << job->task << std::endl; } if( !DAEMON || once ) { diff --git a/src/apps/signer.cpp b/src/apps/signer.cpp index ec85009..44f05d6 100644 --- a/src/apps/signer.cpp +++ b/src/apps/signer.cpp @@ -19,8 +19,6 @@ #define DAEMON true #endif -int handlermain( int argc, const char* argv[] ); - extern std::string serialPath; extern std::vector profiles; diff --git a/src/database.h b/src/database.h index ca90bd4..f23f610 100644 --- a/src/database.h +++ b/src/database.h @@ -6,6 +6,7 @@ struct Job { std::string id; + std::string warning; std::string target; std::string task; std::string from; @@ -50,7 +51,8 @@ struct SignedCertificate { class JobProvider { public: virtual std::shared_ptr fetchJob() = 0; - virtual bool finishJob( std::shared_ptr job ) = 0; + virtual void finishJob( std::shared_ptr job ) = 0; + virtual void failJob( std::shared_ptr job ) = 0; virtual std::shared_ptr fetchTBSCert( std::shared_ptr job ) = 0; virtual void writeBack( std::shared_ptr job, std::shared_ptr res ) = 0; }; diff --git a/src/mysql.cpp b/src/mysql.cpp index bd6929e..15478ac 100644 --- a/src/mysql.cpp +++ b/src/mysql.cpp @@ -113,7 +113,7 @@ std::pair< int, std::shared_ptr > MySQLJobProvider::query( const std: } std::shared_ptr MySQLJobProvider::fetchJob() { - std::string q = "SELECT id, targetId, task, executeFrom, executeTo FROM jobs WHERE state='open'"; + std::string q = "SELECT id, targetId, task, executeFrom, executeTo, warning FROM jobs WHERE state='open' AND warning < 3"; int err = 0; std::shared_ptr res; @@ -145,6 +145,7 @@ std::shared_ptr MySQLJobProvider::fetchJob() { job->task = std::string( row[2], row[2] + l[2] ); job->from = std::string( row[3], row[3] + l[3] ); job->to = std::string( row[4], row[4] + l[4] ); + job->warning = std::string( row[5], row[5] + l[5] ); for( unsigned int i = 0; i < num; i++ ) { printf( "[%.*s] ", ( int ) l[i], row[i] ? row[i] : "NULL" ); @@ -171,18 +172,29 @@ std::string MySQLJobProvider::escape_string( const std::string& target ) { return result; } -bool MySQLJobProvider::finishJob( std::shared_ptr job ) { +void MySQLJobProvider::finishJob( std::shared_ptr job ) { if( !conn ) { - return false; + throw "Not connected!"; } std::string q = "UPDATE jobs SET state='done' WHERE id='" + this->escape_string( job->id ) + "' LIMIT 1"; if( query( q ).first ) { - return false; + throw "No database entry found."; } - return true; +} + +void MySQLJobProvider::failJob( std::shared_ptr job ) { + if( !conn ) { + throw "Not connected!"; + } + + std::string q = "UPDATE jobs SET warning = warning + 1 WHERE id='" + this->escape_string( job->id ) + "' LIMIT 1"; + + if( query( q ).first ) { + throw "No database entry found."; + } } std::shared_ptr MySQLJobProvider::fetchTBSCert( std::shared_ptr job ) { diff --git a/src/mysql.h b/src/mysql.h index da13e58..b1f78ce 100644 --- a/src/mysql.h +++ b/src/mysql.h @@ -31,7 +31,8 @@ public: public: std::shared_ptr fetchJob(); - bool finishJob( std::shared_ptr job ); + void finishJob( std::shared_ptr job ); + void failJob( std::shared_ptr job ); std::shared_ptr fetchTBSCert( std::shared_ptr job ); void writeBack( std::shared_ptr job, std::shared_ptr res ); }; diff --git a/src/record.cpp b/src/record.cpp index 5993b60..8f81d02 100644 --- a/src/record.cpp +++ b/src/record.cpp @@ -23,13 +23,18 @@ std::string toHexAndChecksum( const std::string& src ) { return ss.str(); } -void sendCommand( RecordHeader& head, const std::string& data, std::shared_ptr bio ) { +void sendCommand( RecordHeader& head, const std::string& data, std::shared_ptr bio, std::shared_ptr log ) { head.payloadLength = data.size(); std::string s; s += head.packToString(); s += data; std::string res = toHexAndChecksum( s ); + + if( log ) { + ( *log.get() ) << "FINE: RECORD output: " << res << std::endl; + } + bio->write( res.data(), res.size() ); } @@ -47,7 +52,11 @@ int32_t fromHexDigit( char c ) { return res; } -std::string parseCommand( RecordHeader& head, const std::string& input ) { +std::string parseCommand( RecordHeader& head, const std::string input, std::shared_ptr log ) { + if( log ) { + ( *log.get() ) << "FINE: RECORD input: " << input << std::endl; + } + int32_t dlen = ( input.size() - 2 ) / 2; char checksum = 0; bool error = false; diff --git a/src/record.h b/src/record.h index 03746ed..d3173b8 100644 --- a/src/record.h +++ b/src/record.h @@ -88,6 +88,6 @@ public: }; -std::string parseCommand( RecordHeader& head, const std::string& input ); +std::string parseCommand( RecordHeader& head, const std::string input, std::shared_ptr log ); -void sendCommand( RecordHeader& head, const std::string& data, std::shared_ptr bio ); +void sendCommand( RecordHeader& head, const std::string& data, std::shared_ptr bio, std::shared_ptr log ); diff --git a/src/recordHandler.cpp b/src/recordHandler.cpp index 7412b0c..dd5201b 100644 --- a/src/recordHandler.cpp +++ b/src/recordHandler.cpp @@ -8,6 +8,8 @@ #include #include +#include +#include #include @@ -35,10 +37,24 @@ public: DefaultRecordHandler* parent; std::shared_ptr signer; + std::shared_ptr log; + RecordHandlerSession( DefaultRecordHandler* parent, std::shared_ptr signer, std::shared_ptr ctx, std::shared_ptr output ) : tbs( new TBSCertificate() ) { this->parent = parent; this->signer = signer; + time_t c_time; + + if( time( &c_time ) == -1 ) { + throw "Error while fetching time?"; + } + + log = std::shared_ptr( + new std::ofstream( std::string( "logs/log_" ) + std::to_string( c_time ) ), + []( std::ofstream * ptr ) { + ptr->close(); + delete ptr; + } ); ssl = std::shared_ptr( SSL_new( ctx.get() ), SSL_free ); std::shared_ptr bio( @@ -58,7 +74,7 @@ public: rh.flags = 0; rh.command_count = 0; // TODO i++ rh.totalLength = payload.size(); - sendCommand( rh, payload, io ); + sendCommand( rh, payload, io, log ); } void work() { @@ -74,10 +90,13 @@ public: try { RecordHeader head; - std::string payload = parseCommand( head, content ); + std::string payload = parseCommand( head, content, log ); execute( head, payload ); } catch( const char* msg ) { - std::cout << msg << std::endl; + if( log ) { + ( *log ) << "ERROR: " << msg << std::endl; + } + parent->reset(); return; } @@ -92,7 +111,7 @@ public: case RecordHeader::SignerCommand::SET_CSR: // setCSR tbs->csr_content = data; tbs->csr_type = "CSR"; - std::cout << "CSR read" << std::endl; + ( *log ) << "INFO: CSR read:" << std::endl << tbs->csr_content; break; case RecordHeader::SignerCommand::SET_SIGNATURE_TYPE: @@ -136,8 +155,8 @@ public: case RecordHeader::SignerCommand::SIGN: result = signer->sign( tbs ); - std::cout << "res: " << result->certificate << std::endl; - result->log = "I am a dummy log.\nI signed that thing ;-) \n"; + ( *log ) << "INFO: signlog: " << result->log << std::endl; + ( *log ) << "INFO: res: " << result->certificate << std::endl; respondCommand( RecordHeader::SignerResult::SAVE_LOG, result->log ); break; @@ -147,7 +166,7 @@ public: } if( !SSL_shutdown( ssl.get() ) && !SSL_shutdown( ssl.get() ) ) { - std::cout << "SSL close failed" << std::endl; + ( *log ) << "ERROR: SSL close failed" << std::endl; } break; diff --git a/src/remoteSigner.cpp b/src/remoteSigner.cpp index a17f515..7171400 100644 --- a/src/remoteSigner.cpp +++ b/src/remoteSigner.cpp @@ -13,7 +13,7 @@ void RemoteSigner::send( std::shared_ptr bio, RecordHeader& h head.command = ( uint16_t ) cmd; head.command_count++; head.totalLength = data.size(); - sendCommand( head, data, bio ); + sendCommand( head, data, bio, log ); } @@ -72,7 +72,7 @@ std::shared_ptr RemoteSigner::sign( std::shared_ptr RemoteSigner::sign( std::shared_ptr target ) { + this->log = target; +} diff --git a/src/remoteSigner.h b/src/remoteSigner.h index 36c9339..8cc3c72 100644 --- a/src/remoteSigner.h +++ b/src/remoteSigner.h @@ -13,10 +13,12 @@ class RemoteSigner : public Signer { private: std::shared_ptr target; std::shared_ptr ctx; + std::shared_ptr log; int count = 0; void send( std::shared_ptr bio, RecordHeader& head, RecordHeader::SignerCommand cmd, std::string data ); public: RemoteSigner( std::shared_ptr target, std::shared_ptr ctx ); ~RemoteSigner(); std::shared_ptr sign( std::shared_ptr cert ); + void setLog( std::shared_ptr target ); }; diff --git a/src/simpleOpensslSigner.cpp b/src/simpleOpensslSigner.cpp index 749131b..83c5609 100644 --- a/src/simpleOpensslSigner.cpp +++ b/src/simpleOpensslSigner.cpp @@ -1,6 +1,7 @@ #include "simpleOpensslSigner.h" #include +#include #include #include @@ -66,10 +67,14 @@ std::shared_ptr SimpleOpensslSigner::nextSerial( uint16_t profile ) { } std::shared_ptr SimpleOpensslSigner::sign( std::shared_ptr cert ) { + std::stringstream signlog; + if( !prof.ca ) { throw "CA-key not found"; } + signlog << "FINE: CA-key is correctly loaded." << std::endl; + std::shared_ptr req; if( cert->csr_type == "SPKAC" ) { @@ -87,7 +92,7 @@ std::shared_ptr SimpleOpensslSigner::sign( std::shared_ptr SimpleOpensslSigner::sign( std::shared_ptr a : cert->AVAs ) { + signlog << "Addings RDN: " << a->name << ": " << a->value << std::endl; + if( a->name == "CN" ) { c.addRDN( NID_commonName, a->value ); } else if( a->name == "EMAIL" ) { @@ -136,9 +143,11 @@ std::shared_ptr SimpleOpensslSigner::sign( std::shared_ptr ser = nextSerial( profile ); c.setSerialNumber( ser.get() ); c.setTimes( 0, 60 * 60 * 24 * 10 ); + signlog << "FINE: Setting extensions." << std::endl; c.setExtensions( prof.ca, cert->SANs ); - + signlog << "FINE: Signed" << std::endl; std::shared_ptr output = c.sign( prof.caKey, cert->md ); - + signlog << "FINE: all went well" << std::endl; + output->log = signlog.str(); return output; } -- 2.39.2