From 4899e0d2d56bb3ccd8727b7f87c67fce86e6cae4 Mon Sep 17 00:00:00 2001 From: hagen Date: Thu, 17 Dec 2015 07:11:36 +0000 Subject: [PATCH 01/32] * sane log messages: I2NPProtocol.cpp --- I2NPProtocol.cpp | 40 +++++++++++++++++----------------------- 1 file changed, 17 insertions(+), 23 deletions(-) diff --git a/I2NPProtocol.cpp b/I2NPProtocol.cpp index 6f7c98f5..63c8ea9c 100644 --- a/I2NPProtocol.cpp +++ b/I2NPProtocol.cpp @@ -60,7 +60,7 @@ namespace i2p msg->len += len; } else - LogPrint (eLogError, "I2NP message length ", len, " exceeds max length"); + LogPrint (eLogError, "I2NP: message length ", len, " exceeds max length"); msg->FillI2NPMessageHeader (msgType, replyMsgID); return msg; } @@ -75,7 +75,7 @@ namespace i2p msg->from = from; } else - LogPrint (eLogError, "I2NP message length ", len, " exceeds max length"); + LogPrint (eLogError, "I2NP: message length ", len, " exceeds max length"); return msg; } @@ -276,7 +276,7 @@ namespace i2p uint8_t * record = records + i*TUNNEL_BUILD_RECORD_SIZE; if (!memcmp (record + BUILD_REQUEST_RECORD_TO_PEER_OFFSET, (const uint8_t *)i2p::context.GetRouterInfo ().GetIdentHash (), 16)) { - LogPrint ("Record ",i," is ours"); + LogPrint (eLogDebug, "I2NP: Build request record ", i, " is ours"); i2p::crypto::ElGamalDecrypt (i2p::context.GetEncryptionPrivateKey (), record + BUILD_REQUEST_RECORD_ENCRYPTED_OFFSET, clearText); // replace record to reply @@ -320,22 +320,22 @@ namespace i2p void HandleVariableTunnelBuildMsg (uint32_t replyMsgID, uint8_t * buf, size_t len) { int num = buf[0]; - LogPrint ("VariableTunnelBuild ", num, " records"); + LogPrint (eLogDebug, "I2NP: VariableTunnelBuild ", num, " records"); auto tunnel = i2p::tunnel::tunnels.GetPendingInboundTunnel (replyMsgID); if (tunnel) { // endpoint of inbound tunnel - LogPrint ("VariableTunnelBuild reply for tunnel ", tunnel->GetTunnelID ()); + LogPrint (eLogDebug, "I2NP: VariableTunnelBuild reply for tunnel ", tunnel->GetTunnelID ()); if (tunnel->HandleTunnelBuildResponse (buf, len)) { - LogPrint ("Inbound tunnel ", tunnel->GetTunnelID (), " has been created"); + LogPrint (eLogInfo, "I2NP: Inbound tunnel ", tunnel->GetTunnelID (), " has been created"); tunnel->SetState (i2p::tunnel::eTunnelStateEstablished); i2p::tunnel::tunnels.AddInboundTunnel (tunnel); } else { - LogPrint ("Inbound tunnel ", tunnel->GetTunnelID (), " has been declined"); + LogPrint (eLogInfo, "I2NP: Inbound tunnel ", tunnel->GetTunnelID (), " has been declined"); tunnel->SetState (i2p::tunnel::eTunnelStateBuildFailed); } } @@ -382,25 +382,25 @@ namespace i2p void HandleVariableTunnelBuildReplyMsg (uint32_t replyMsgID, uint8_t * buf, size_t len) { - LogPrint ("VariableTunnelBuildReplyMsg replyMsgID=", replyMsgID); + LogPrint (eLogDebug, "I2NP: VariableTunnelBuildReplyMsg replyMsgID=", replyMsgID); auto tunnel = i2p::tunnel::tunnels.GetPendingOutboundTunnel (replyMsgID); if (tunnel) { // reply for outbound tunnel if (tunnel->HandleTunnelBuildResponse (buf, len)) { - LogPrint ("Outbound tunnel ", tunnel->GetTunnelID (), " has been created"); + LogPrint (eLogInfo, "I2NP: Outbound tunnel ", tunnel->GetTunnelID (), " has been created"); tunnel->SetState (i2p::tunnel::eTunnelStateEstablished); i2p::tunnel::tunnels.AddOutboundTunnel (tunnel); } else { - LogPrint ("Outbound tunnel ", tunnel->GetTunnelID (), " has been declined"); + LogPrint (eLogInfo, "I2NP: Outbound tunnel ", tunnel->GetTunnelID (), " has been declined"); tunnel->SetState (i2p::tunnel::eTunnelStateBuildFailed); } } else - LogPrint ("Pending tunnel for message ", replyMsgID, " not found"); + LogPrint (eLogWarning, "I2NP: Pending tunnel for message ", replyMsgID, " not found"); } @@ -488,30 +488,26 @@ namespace i2p { uint8_t typeID = msg[I2NP_HEADER_TYPEID_OFFSET]; uint32_t msgID = bufbe32toh (msg + I2NP_HEADER_MSGID_OFFSET); - LogPrint ("I2NP msg received len=", len,", type=", (int)typeID, ", msgID=", (unsigned int)msgID); + LogPrint (eLogDebug, "I2NP: msg received len=", len,", type=", (int)typeID, ", msgID=", (unsigned int)msgID); uint8_t * buf = msg + I2NP_HEADER_SIZE; int size = bufbe16toh (msg + I2NP_HEADER_SIZE_OFFSET); switch (typeID) { case eI2NPVariableTunnelBuild: - LogPrint ("VariableTunnelBuild"); HandleVariableTunnelBuildMsg (msgID, buf, size); break; case eI2NPVariableTunnelBuildReply: - LogPrint ("VariableTunnelBuildReply"); HandleVariableTunnelBuildReplyMsg (msgID, buf, size); break; case eI2NPTunnelBuild: - LogPrint ("TunnelBuild"); HandleTunnelBuildMsg (buf, size); break; case eI2NPTunnelBuildReply: - LogPrint ("TunnelBuildReply"); // TODO: break; default: - LogPrint ("Unexpected message ", (int)typeID); + LogPrint (eLogWarning, "I2NP: Unexpected message ", (int)typeID); } } @@ -519,25 +515,24 @@ namespace i2p { if (msg) { - switch (msg->GetTypeID ()) + uint8_t typeID = msg->GetTypeID (); + LogPrint (eLogDebug, "I2NP: Got message with type ", (int)typeID); + switch (typeID) { case eI2NPTunnelData: - LogPrint ("TunnelData"); i2p::tunnel::tunnels.PostTunnelData (msg); break; case eI2NPTunnelGateway: - LogPrint ("TunnelGateway"); i2p::tunnel::tunnels.PostTunnelData (msg); break; case eI2NPGarlic: { - LogPrint ("Garlic"); if (msg->from) { if (msg->from->GetTunnelPool ()) msg->from->GetTunnelPool ()->ProcessGarlicMessage (msg); else - LogPrint (eLogInfo, "Local destination for garlic doesn't exist anymore"); + LogPrint (eLogInfo, "I2NP: Local destination for garlic doesn't exist anymore"); } else i2p::context.ProcessGarlicMessage (msg); @@ -551,7 +546,6 @@ namespace i2p break; case eI2NPDeliveryStatus: { - LogPrint ("DeliveryStatus"); if (msg->from && msg->from->GetTunnelPool ()) msg->from->GetTunnelPool ()->ProcessDeliveryStatus (msg); else From 489e37b2a16150fe5f8e007d79c1a41c24649d56 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 04:03:07 +0000 Subject: [PATCH 02/32] * sane log messages: NetDb.cpp --- NetDb.cpp | 85 +++++++++++++++++++++++++++---------------------------- 1 file changed, 41 insertions(+), 44 deletions(-) diff --git a/NetDb.cpp b/NetDb.cpp index d1f8ef14..e6269959 100644 --- a/NetDb.cpp +++ b/NetDb.cpp @@ -80,22 +80,20 @@ namespace data int numMsgs = 0; while (msg) { + LogPrint(eLogDebug, "NetDb: got request with type ", (int) msg->GetTypeID ()); switch (msg->GetTypeID ()) { case eI2NPDatabaseStore: - LogPrint ("DatabaseStore"); HandleDatabaseStoreMsg (msg); break; case eI2NPDatabaseSearchReply: - LogPrint ("DatabaseSearchReply"); HandleDatabaseSearchReplyMsg (msg); break; case eI2NPDatabaseLookup: - LogPrint ("DatabaseLookup"); HandleDatabaseLookupMsg (msg); break; default: // WTF? - LogPrint (eLogError, "NetDb: unexpected message type ", msg->GetTypeID ()); + LogPrint (eLogError, "NetDb: unexpected message type ", (int) msg->GetTypeID ()); //i2p::HandleI2NPMessage (msg); } if (numMsgs > 100) break; @@ -141,7 +139,7 @@ namespace data } catch (std::exception& ex) { - LogPrint ("NetDb: ", ex.what ()); + LogPrint (eLogError, "NetDb: runtime exception: ", ex.what ()); } } } @@ -161,11 +159,11 @@ namespace data auto ts = r->GetTimestamp (); r->Update (buf, len); if (r->GetTimestamp () > ts) - LogPrint ("RouterInfo updated"); + LogPrint (eLogInfo, "NetDb: RouterInfo updated: ", ident.ToBase32()); } else { - LogPrint ("New RouterInfo added"); + LogPrint (eLogInfo, "NetDb: RouterInfo added: ", ident.ToBase32()); r = std::make_shared (buf, len); { std::unique_lock l(m_RouterInfosMutex); @@ -191,10 +189,10 @@ namespace data { it->second->Update (buf, len); if (it->second->IsValid ()) - LogPrint (eLogInfo, "LeaseSet updated"); + LogPrint (eLogInfo, "NetDb: LeaseSet updated: ", ident.ToBase32()); else { - LogPrint (eLogInfo, "LeaseSet update failed"); + LogPrint (eLogWarning, "NetDb: LeaseSet update failed: ", ident.ToBase32()); m_LeaseSets.erase (it); } } @@ -203,11 +201,11 @@ namespace data auto leaseSet = std::make_shared (buf, len); if (leaseSet->IsValid ()) { - LogPrint (eLogInfo, "New LeaseSet added"); + LogPrint (eLogInfo, "NetDb: LeaseSet added: ", ident.ToBase32()); m_LeaseSets[ident] = leaseSet; } else - LogPrint (eLogError, "New LeaseSet validation failed"); + LogPrint (eLogError, "NetDb: new LeaseSet validation failed: ", ident.ToBase32()); } } } @@ -247,10 +245,10 @@ namespace data // TODO: Move to reseed and/or scheduled tasks. (In java version, scheduler fix this as well as sort RIs.) bool NetDb::CreateNetDb(boost::filesystem::path directory) { - LogPrint (directory.string(), " doesn't exist, trying to create it."); + LogPrint (eLogInfo, "NetDb: storage directory doesn't exist, trying to create it."); if (!boost::filesystem::create_directory (directory)) { - LogPrint (eLogError, "Failed to create directory ", directory); + LogPrint (eLogError, "NetDb: failed to create directory ", directory); return false; } @@ -261,7 +259,7 @@ namespace data auto p = directory / (std::string ("r") + chars[i]); if (!boost::filesystem::exists (p) && !boost::filesystem::create_directory (p)) { - LogPrint (eLogError, "Failed to create directory ", p); + LogPrint (eLogError, "NetDb: failed to create directory ", p); return false; } } @@ -279,7 +277,7 @@ namespace data while (reseedRetries < 10 && !m_Reseeder->ReseedNowSU3 ()) reseedRetries++; if (reseedRetries >= 10) - LogPrint (eLogWarning, "Failed to reseed after 10 attempts"); + LogPrint (eLogWarning, "NetDb: failed to reseed after 10 attempts"); } void NetDb::Load () @@ -327,8 +325,7 @@ namespace data } } } - LogPrint (numRouters, " routers loaded"); - LogPrint (m_Floodfills.size (), " floodfills loaded"); + LogPrint (eLogInfo, "NetDb: ", numRouters, " routers loaded (", m_Floodfills.size (), " floodfils)"); } void NetDb::SaveUpdated () @@ -406,10 +403,10 @@ namespace data } } if (count > 0) - LogPrint (count," new/updated routers saved"); + LogPrint (eLogInfo, "NetDb: ", count, " new/updated routers saved"); if (deletedCount > 0) { - LogPrint (deletedCount," routers deleted"); + LogPrint (eLogDebug, "NetDb: ", deletedCount, " routers deleted"); // clean up RouterInfos table std::unique_lock l(m_RouterInfosMutex); for (auto it = m_RouterInfos.begin (); it != m_RouterInfos.end ();) @@ -430,7 +427,7 @@ namespace data auto dest = m_Requests.CreateRequest (destination, false, requestComplete); // non-exploratory if (!dest) { - LogPrint (eLogWarning, "Destination ", destination.ToBase64(), " is requested already"); + LogPrint (eLogWarning, "NetDb: destination ", destination.ToBase32(), " is requested already"); return; } @@ -439,7 +436,7 @@ namespace data transports.SendMessage (floodfill->GetIdentHash (), dest->CreateRequestMessage (floodfill->GetIdentHash ())); else { - LogPrint (eLogError, "No floodfills found"); + LogPrint (eLogError, "NetDb: ", destination.ToBase32(), " destination requested, but no floodfills found"); m_Requests.RequestComplete (destination, nullptr); } } @@ -451,7 +448,7 @@ namespace data IdentHash ident (buf + DATABASE_STORE_KEY_OFFSET); if (ident.IsZero ()) { - LogPrint (eLogError, "Database store with zero ident. Dropped"); + LogPrint (eLogError, "NetDb: database store with zero ident, dropped"); return; } uint32_t replyToken = bufbe32toh (buf + DATABASE_STORE_REPLY_TOKEN_OFFSET); @@ -470,7 +467,7 @@ namespace data if (outbound) outbound->SendTunnelDataMsg (buf + offset, tunnelID, deliveryStatus); else - LogPrint (eLogError, "No outbound tunnels for DatabaseStore reply found"); + LogPrint (eLogError, "NetDb: no outbound tunnels for DatabaseStore reply found"); } offset += 32; @@ -496,17 +493,17 @@ namespace data if (buf[DATABASE_STORE_TYPE_OFFSET]) // type { - LogPrint ("LeaseSet"); + LogPrint (eLogDebug, "NetDb: store request: LeaseSet"); AddLeaseSet (ident, buf + offset, len - offset, m->from); } else { - LogPrint ("RouterInfo"); + LogPrint (eLogDebug, "NetDb: store request: RouterInfo"); size_t size = bufbe16toh (buf + offset); offset += 2; if (size > 2048 || size > len - offset) { - LogPrint ("Invalid RouterInfo length ", (int)size); + LogPrint (eLogError, "NetDb: invalid RouterInfo length ", (int)size); return; } uint8_t uncompressed[2048]; @@ -523,7 +520,7 @@ namespace data int l = i2p::data::ByteStreamToBase64 (buf, 32, key, 48); key[l] = 0; int num = buf[32]; // num - LogPrint ("DatabaseSearchReply for ", key, " num=", num); + LogPrint (eLogDebug, "NetDb: DatabaseSearchReply for ", key, " num=", num); IdentHash ident (buf); auto dest = m_Requests.FindRequest (ident); if (dest) @@ -555,7 +552,7 @@ namespace data }); // request destination - LogPrint ("Try ", key, " at ", count, " floodfill ", nextFloodfill->GetIdentHash ().ToBase64 ()); + LogPrint (eLogDebug, "NetDb: Try ", key, " at ", count, " floodfill ", nextFloodfill->GetIdentHash ().ToBase64 ()); auto msg = dest->CreateRequestMessage (nextFloodfill, inbound); msgs.push_back (i2p::tunnel::TunnelMessageBlock { @@ -566,7 +563,7 @@ namespace data } } else - LogPrint (key, " was not found on 7 floodfills"); + LogPrint (eLogWarning, "NetDb: ", key, " was not found on ", count, " floodfills"); if (msgs.size () > 0) outbound->SendTunnelDataMsg (msgs); @@ -582,7 +579,7 @@ namespace data m_Requests.RequestComplete (ident, nullptr); } else - LogPrint ("Requested destination for ", key, " not found"); + LogPrint (eLogWarning, "NetDb: requested destination for ", key, " not found"); // try responses for (int i = 0; i < num; i++) @@ -591,17 +588,17 @@ namespace data char peerHash[48]; int l1 = i2p::data::ByteStreamToBase64 (router, 32, peerHash, 48); peerHash[l1] = 0; - LogPrint (i,": ", peerHash); + LogPrint (eLogDebug, "NetDb: ", i, ": ", peerHash); auto r = FindRouter (router); if (!r || i2p::util::GetMillisecondsSinceEpoch () > r->GetTimestamp () + 3600*1000LL) { // router with ident not found or too old (1 hour) - LogPrint ("Found new/outdated router. Requesting RouterInfo ..."); + LogPrint (eLogDebug, "NetDb: found new/outdated router. Requesting RouterInfo ..."); RequestDestination (router); } else - LogPrint ("Bayan"); + LogPrint (eLogDebug, "NetDb: [:|||:]"); } } @@ -611,14 +608,14 @@ namespace data IdentHash ident (buf); if (ident.IsZero ()) { - LogPrint (eLogError, "DatabaseLookup for zero ident. Ignored"); + LogPrint (eLogError, "NetDb: DatabaseLookup for zero ident. Ignored"); return; } char key[48]; int l = i2p::data::ByteStreamToBase64 (buf, 32, key, 48); key[l] = 0; uint8_t flag = buf[64]; - LogPrint ("DatabaseLookup for ", key, " recieved flags=", (int)flag); + LogPrint (eLogDebug, "NetDb: DatabaseLookup for ", key, " recieved flags=", (int)flag); uint8_t lookupType = flag & DATABASE_LOOKUP_TYPE_FLAGS_MASK; const uint8_t * excluded = buf + 65; uint32_t replyTunnelID = 0; @@ -631,14 +628,14 @@ namespace data excluded += 2; if (numExcluded > 512) { - LogPrint ("Number of excluded peers", numExcluded, " exceeds 512"); + LogPrint (eLogWarning, "NetDb: number of excluded peers", numExcluded, " exceeds 512"); numExcluded = 0; // TODO: } std::shared_ptr replyMsg; if (lookupType == DATABASE_LOOKUP_TYPE_EXPLORATORY_LOOKUP) { - LogPrint ("Exploratory close to ", key, " ", numExcluded, " excluded"); + LogPrint (eLogInfo, "NetDb: exploratory close to ", key, " ", numExcluded, " excluded"); std::set excludedRouters; for (int i = 0; i < numExcluded; i++) { @@ -665,7 +662,7 @@ namespace data auto router = FindRouter (ident); if (router) { - LogPrint ("Requested RouterInfo ", key, " found"); + LogPrint (eLogDebug, "NetDb: requested RouterInfo ", key, " found"); router->LoadBuffer (); if (router->GetBuffer ()) replyMsg = CreateDatabaseStoreMsg (router); @@ -678,14 +675,14 @@ namespace data auto leaseSet = FindLeaseSet (ident); if (leaseSet) // we don't send back our LeaseSets { - LogPrint ("Requested LeaseSet ", key, " found"); + LogPrint (eLogDebug, "NetDb: requested LeaseSet ", key, " found"); replyMsg = CreateDatabaseStoreMsg (leaseSet); } } if (!replyMsg) { - LogPrint ("Requested ", key, " not found. ", numExcluded, " excluded"); + LogPrint (eLogWarning, "NetDb: Requested ", key, " not found. ", numExcluded, " excluded"); std::set excludedRouters; for (int i = 0; i < numExcluded; i++) { @@ -735,14 +732,14 @@ namespace data uint8_t randomHash[32]; std::vector msgs; std::set floodfills; - LogPrint ("Exploring new ", numDestinations, " routers ..."); + LogPrint (eLogInfo, "NetDb: exploring new ", numDestinations, " routers ..."); for (int i = 0; i < numDestinations; i++) { RAND_bytes (randomHash, 32); auto dest = m_Requests.CreateRequest (randomHash, true); // exploratory if (!dest) { - LogPrint (eLogWarning, "Exploratory destination is requested already"); + LogPrint (eLogWarning, "NetDb: exploratory destination is requested already"); return; } auto floodfill = GetClosestFloodfill (randomHash, dest->GetExcludedPeers ()); @@ -786,7 +783,7 @@ namespace data { uint32_t replyToken; RAND_bytes ((uint8_t *)&replyToken, 4); - LogPrint ("Publishing our RouterInfo to ", i2p::data::GetIdentHashAbbreviation(floodfill->GetIdentHash ()), ". reply token=", replyToken); + LogPrint (eLogInfo, "NetDb: Publishing our RouterInfo to ", i2p::data::GetIdentHashAbbreviation(floodfill->GetIdentHash ()), ". reply token=", replyToken); transports.SendMessage (floodfill->GetIdentHash (), CreateDatabaseStoreMsg (i2p::context.GetSharedRouterInfo (), replyToken)); excluded.insert (floodfill->GetIdentHash ()); } @@ -972,7 +969,7 @@ namespace data { if (!it->second->HasNonExpiredLeases ()) // all leases expired { - LogPrint ("LeaseSet ", it->second->GetIdentHash ().ToBase64 (), " expired"); + LogPrint (eLogWarning, "NetDb: LeaseSet ", it->second->GetIdentHash ().ToBase64 (), " expired"); it = m_LeaseSets.erase (it); } else From 8170257c2602a6851eea1a302c59875e9513e46e Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 04:05:52 +0000 Subject: [PATCH 03/32] * sane log messages: AddressBook.cpp --- AddressBook.cpp | 15 +++++++++------ 1 file changed, 9 insertions(+), 6 deletions(-) diff --git a/AddressBook.cpp b/AddressBook.cpp index 49177e8e..6be1c0eb 100644 --- a/AddressBook.cpp +++ b/AddressBook.cpp @@ -152,10 +152,10 @@ namespace client num++; } } - LogPrint (eLogInfo, num, " addresses loaded"); + LogPrint (eLogInfo, "Addressbook: ", num, " addresses loaded"); } else - LogPrint (eLogWarning, filename, " not found"); + LogPrint (eLogWarning, "Addressbook: ", filename, " not found"); return num; } @@ -171,7 +171,7 @@ namespace client f << it.first << "," << it.second.ToBase32 () << std::endl; num++; } - LogPrint (eLogInfo, num, " addresses saved"); + LogPrint (eLogInfo, "Addressbook: ", num, " addresses saved"); } else LogPrint (eLogError, "Can't open file ", filename); @@ -290,7 +290,7 @@ namespace client m_Storage = CreateStorage (); m_Storage->AddAddress (ident); m_Addresses[address] = ident->GetIdentHash (); - LogPrint (address,"->", ToAddress(ident->GetIdentHash ()), " added"); + LogPrint (eLogInfo, "Addressbook: ", address,"->", ToAddress(ident->GetIdentHash ()), " added"); } void AddressBook::InsertAddress (std::shared_ptr address) @@ -476,7 +476,7 @@ namespace client void AddressBookSubscription::Request () { // must be run in separate thread - LogPrint (eLogInfo, "Downloading hosts from ", m_Link, " ETag: ", m_Etag, " Last-Modified: ", m_LastModified); + LogPrint (eLogInfo, "Downloading hosts database from ", m_Link, " ETag: ", m_Etag, " Last-Modified: ", m_LastModified); bool success = false; i2p::util::http::url u (m_Link); i2p::data::IdentHash ident; @@ -591,7 +591,10 @@ namespace client } else LogPrint (eLogError, "Can't resolve ", u.host_); - LogPrint (eLogInfo, "Download complete ", success ? "Success" : "Failed"); + + if (!success) + LogPrint (eLogError, "Addressbook download failed"); + m_Book.DownloadComplete (success); } } From facc5f8aa732522f25514520de77304bd05280f5 Mon Sep 17 00:00:00 2001 From: hagen Date: Thu, 17 Dec 2015 08:09:54 +0000 Subject: [PATCH 04/32] * sane log messages: SSUSession.cpp --- SSUSession.cpp | 96 +++++++++++++++++++++++++------------------------- 1 file changed, 48 insertions(+), 48 deletions(-) diff --git a/SSUSession.cpp b/SSUSession.cpp index 1516b6c2..a91ecc2d 100644 --- a/SSUSession.cpp +++ b/SSUSession.cpp @@ -70,7 +70,7 @@ namespace transport nonZero++; if (nonZero - sharedKey > 32) { - LogPrint ("First 32 bytes of shared key is all zeros. Ignored"); + LogPrint (eLogWarning, "SSU: first 32 bytes of shared key is all zeros. Ignored"); return; } } @@ -90,7 +90,7 @@ namespace transport if (m_State == eSessionStateIntroduced) { // HolePunch received - LogPrint ("SSU HolePunch of ", len, " bytes received"); + LogPrint (eLogDebug, "SSU: HolePunch of ", len, " bytes received"); m_State = eSessionStateUnknown; Connect (); } @@ -120,7 +120,7 @@ namespace transport Decrypt (buf, len, address->key); else { - LogPrint (eLogError, "MAC verification failed ", len, " bytes from ", senderEndpoint); + LogPrint (eLogError, "SSU: MAC verification failed ", len, " bytes from ", senderEndpoint); m_Server.DeleteSession (shared_from_this ()); return; } @@ -166,12 +166,12 @@ namespace transport ProcessSessionConfirmed (buf, len); // buf with header break; case PAYLOAD_TYPE_PEER_TEST: - LogPrint (eLogDebug, "SSU peer test received"); + LogPrint (eLogDebug, "SSU: peer test received"); ProcessPeerTest (buf + headerSize, len - headerSize, senderEndpoint); break; case PAYLOAD_TYPE_SESSION_DESTROYED: { - LogPrint (eLogDebug, "SSU session destroy received"); + LogPrint (eLogDebug, "SSU: session destroy received"); m_Server.DeleteSession (shared_from_this ()); break; } @@ -181,21 +181,21 @@ namespace transport m_Server.DeleteSession (shared_from_this ()); break; case PAYLOAD_TYPE_RELAY_REQUEST: - LogPrint (eLogDebug, "SSU relay request received"); + LogPrint (eLogDebug, "SSU: relay request received"); ProcessRelayRequest (buf + headerSize, len - headerSize, senderEndpoint); break; case PAYLOAD_TYPE_RELAY_INTRO: - LogPrint (eLogDebug, "SSU relay intro received"); + LogPrint (eLogDebug, "SSU: relay intro received"); ProcessRelayIntro (buf + headerSize, len - headerSize); break; default: - LogPrint (eLogWarning, "Unexpected SSU payload type ", (int)header->GetPayloadType ()); + LogPrint (eLogWarning, "SSU: Unexpected payload type ", (int)header->GetPayloadType ()); } } void SSUSession::ProcessSessionRequest (const uint8_t * buf, size_t len, const boost::asio::ip::udp::endpoint& senderEndpoint) { - LogPrint (eLogDebug, "Session request received"); + LogPrint (eLogDebug, "SSU message: session request"); m_RemoteEndpoint = senderEndpoint; if (!m_DHKeysPair) m_DHKeysPair = transports.GetNextDHKeysPair (); @@ -207,11 +207,11 @@ namespace transport { if (!IsOutgoing () || !m_DHKeysPair) { - LogPrint (eLogWarning, "Unsolicited session created message"); + LogPrint (eLogWarning, "SSU: Unsolicited session created message"); return; } - LogPrint (eLogDebug, "Session created received"); + LogPrint (eLogDebug, "SSU message: session created"); m_Timer.cancel (); // connect timer SignedData s; // x,y, our IP, our port, remote IP, remote port, relayTag, signed on time auto headerSize = GetSSUHeaderSize (buf); @@ -247,7 +247,7 @@ namespace transport uint16_t ourPort = bufbe16toh (payload); s.Insert (payload, 2); // our port payload += 2; // port - LogPrint ("Our external address is ", ourIP.to_string (), ":", ourPort); + LogPrint (eLogInfo, "SSU: Our external address is ", ourIP.to_string (), ":", ourPort); i2p::context.UpdateAddress (ourIP); if (m_RemoteEndpoint.address ().is_v4 ()) s.Insert (m_RemoteEndpoint.address ().to_v4 ().to_bytes ().data (), 4); // remote IP v4 @@ -267,18 +267,18 @@ namespace transport m_SessionKeyDecryption.Decrypt (payload, signatureLen, payload); // TODO: non-const payload // verify if (!s.Verify (m_RemoteIdentity, payload)) - LogPrint (eLogError, "Session created SSU signature verification failed"); + LogPrint (eLogError, "SSU: message 'created' signature verification failed"); SendSessionConfirmed (y, ourAddress, addressSize + 2); } void SSUSession::ProcessSessionConfirmed (const uint8_t * buf, size_t len) { - LogPrint (eLogDebug, "Session confirmed received"); + LogPrint (eLogDebug, "SSU: Session confirmed received"); auto headerSize = GetSSUHeaderSize (buf); if (headerSize >= len) { - LogPrint (eLogError, "Session confirmed header size ", len, " exceeds packet length ", len); + LogPrint (eLogError, "SSU: Session confirmed header size ", len, " exceeds packet length ", len); return; } const uint8_t * payload = buf + headerSize; @@ -297,7 +297,7 @@ namespace transport payload += paddingSize; // verify if (m_SignedData && !m_SignedData->Verify (m_RemoteIdentity, payload)) - LogPrint (eLogError, "Session confirmed SSU signature verification failed"); + LogPrint (eLogError, "SSU message 'confirmed' signature verification failed"); m_Data.Send (CreateDeliveryStatusMsg (0)); Established (); } @@ -508,7 +508,7 @@ namespace transport // Charlie's address always v4 if (!to.address ().is_v4 ()) { - LogPrint (eLogError, "Charlie's IP must be v4"); + LogPrint (eLogError, "SSU: Charlie's IP must be v4"); return; } *payload = 4; @@ -551,7 +551,7 @@ namespace transport FillHeaderAndEncrypt (PAYLOAD_TYPE_RELAY_RESPONSE, buf, isV4 ? 64 : 80, introKey, iv, introKey); m_Server.Send (buf, isV4 ? 64 : 80, from); } - LogPrint (eLogDebug, "SSU relay response sent"); + LogPrint (eLogDebug, "SSU: relay response sent"); } void SSUSession::SendRelayIntro (std::shared_ptr session, const boost::asio::ip::udp::endpoint& from) @@ -560,7 +560,7 @@ namespace transport // Alice's address always v4 if (!from.address ().is_v4 ()) { - LogPrint (eLogError, "Alice's IP must be v4"); + LogPrint (eLogError, "SSU: Alice's IP must be v4"); return; } uint8_t buf[48 + 18]; @@ -576,12 +576,12 @@ namespace transport RAND_bytes (iv, 16); // random iv FillHeaderAndEncrypt (PAYLOAD_TYPE_RELAY_INTRO, buf, 48, session->m_SessionKey, iv, session->m_MacKey); m_Server.Send (buf, 48, session->m_RemoteEndpoint); - LogPrint (eLogDebug, "SSU relay intro sent"); + LogPrint (eLogDebug, "SSU: relay intro sent"); } void SSUSession::ProcessRelayResponse (const uint8_t * buf, size_t len) { - LogPrint (eLogDebug, "Relay response received"); + LogPrint (eLogDebug, "SSU message: Relay response received"); uint8_t remoteSize = *buf; buf++; // remote size boost::asio::ip::address_v4 remoteIP (bufbe32toh (buf)); @@ -606,7 +606,7 @@ namespace transport buf += ourSize; // our address uint16_t ourPort = bufbe16toh (buf); buf += 2; // our port - LogPrint ("Our external address is ", ourIP.to_string (), ":", ourPort); + LogPrint (eLogInfo, "SSU: Our external address is ", ourIP.to_string (), ":", ourPort); i2p::context.UpdateAddress (ourIP); uint32_t nonce = bufbe32toh (buf); buf += 4; // nonce @@ -619,7 +619,7 @@ namespace transport { // we didn't have correct endpoint when sent relay request // now we do - LogPrint (eLogInfo, "RelayReponse connecting to endpoint ", remoteEndpoint); + LogPrint (eLogInfo, "SSU: RelayReponse connecting to endpoint ", remoteEndpoint); if (i2p::context.GetRouterInfo ().UsesIntroducer ()) // if we are unreachable m_Server.Send (buf, 0, remoteEndpoint); // send HolePunch m_Server.CreateDirectSession (it->second, remoteEndpoint, false); @@ -628,7 +628,7 @@ namespace transport m_RelayRequests.erase (it); } else - LogPrint (eLogError, "Unsolicited RelayResponse, nonce=", nonce); + LogPrint (eLogError, "SSU: Unsolicited RelayResponse, nonce=", nonce); } void SSUSession::ProcessRelayIntro (const uint8_t * buf, size_t len) @@ -644,7 +644,7 @@ namespace transport m_Server.Send (buf, 0, boost::asio::ip::udp::endpoint (address, port)); } else - LogPrint (eLogWarning, "Address size ", size, " is not supported"); + LogPrint (eLogWarning, "SSU: Address size ", size, " is not supported"); } void SSUSession::FillHeaderAndEncrypt (uint8_t payloadType, uint8_t * buf, size_t len, @@ -652,7 +652,7 @@ namespace transport { if (len < sizeof (SSUHeader)) { - LogPrint (eLogError, "Unexpected SSU packet length ", len); + LogPrint (eLogError, "SSU: Unexpected packet length ", len); return; } //TODO: we are using a dirty solution here but should work for now @@ -676,7 +676,7 @@ namespace transport { if (len < sizeof (SSUHeader)) { - LogPrint (eLogError, "Unexpected SSU packet length ", len); + LogPrint (eLogError, "SSU: Unexpected packet length ", len); return; } //TODO: we are using a dirty solution here but should work for now @@ -698,7 +698,7 @@ namespace transport { if (len < sizeof (SSUHeader)) { - LogPrint (eLogError, "Unexpected SSU packet length ", len); + LogPrint (eLogError, "SSU: Unexpected packet length ", len); return; } //TODO: since we are accessing a uint8_t this is unlikely to crash due to alignment but should be improved @@ -715,7 +715,7 @@ namespace transport { if (len < sizeof (SSUHeader)) { - LogPrint (eLogError, "Unexpected SSU packet length ", len); + LogPrint (eLogError, "SSU: Unexpected packet length ", len); return; } //TODO: since we are accessing a uint8_t this is unlikely to crash due to alignment but should be improved @@ -733,7 +733,7 @@ namespace transport { if (len < sizeof (SSUHeader)) { - LogPrint (eLogError, "Unexpected SSU packet length ", len); + LogPrint (eLogError, "SSU: Unexpected packet length ", len); return false; } //TODO: since we are accessing a uint8_t this is unlikely to crash due to alignment but should be improved @@ -764,7 +764,7 @@ namespace transport if (!IsOutgoing ()) // incoming session ScheduleConnectTimer (); else - LogPrint (eLogError, "SSU wait for connect for outgoing session"); + LogPrint (eLogError, "SSU: wait for connect for outgoing session"); } void SSUSession::ScheduleConnectTimer () @@ -780,7 +780,7 @@ namespace transport if (!ecode) { // timeout expired - LogPrint ("SSU session was not established after ", SSU_CONNECT_TIMEOUT, " second"); + LogPrint (eLogWarning, "SSU: session was not established after ", SSU_CONNECT_TIMEOUT, " seconds"); Failed (); } } @@ -858,7 +858,7 @@ namespace transport { if (ecode != boost::asio::error::operation_aborted) { - LogPrint ("SSU no activity fo ", SSU_TERMINATION_TIMEOUT, " seconds"); + LogPrint (eLogInfo, "SSU: no activity for", SSU_TERMINATION_TIMEOUT, " seconds"); Failed (); } } @@ -902,7 +902,7 @@ namespace transport const uint8_t * introKey = buf + size + 7; if (port && !address) { - LogPrint (eLogWarning, "Address of ", size, " bytes not supported"); + LogPrint (eLogWarning, "SSU: Address of ", size, " bytes not supported"); return; } switch (m_Server.GetPeerTestParticipant (nonce)) @@ -912,13 +912,13 @@ namespace transport { if (m_State == eSessionStateEstablished) { - LogPrint (eLogDebug, "SSU peer test from Bob. We are Alice"); + LogPrint (eLogDebug, "SSU: peer test from Bob. We are Alice"); if (i2p::context.GetStatus () == eRouterStatusTesting) // still not OK i2p::context.SetStatus (eRouterStatusFirewalled); } else { - LogPrint (eLogDebug, "SSU first peer test from Charlie. We are Alice"); + LogPrint (eLogDebug, "SSU: first peer test from Charlie. We are Alice"); i2p::context.SetStatus (eRouterStatusOK); m_Server.UpdatePeerTest (nonce, ePeerTestParticipantAlice2); SendPeerTest (nonce, senderEndpoint.address ().to_v4 ().to_ulong (), @@ -929,11 +929,11 @@ namespace transport case ePeerTestParticipantAlice2: { if (m_State == eSessionStateEstablished) - LogPrint (eLogDebug, "SSU peer test from Bob. We are Alice"); + LogPrint (eLogDebug, "SSU: peer test from Bob. We are Alice"); else { // peer test successive - LogPrint (eLogDebug, "SSU second peer test from Charlie. We are Alice"); + LogPrint (eLogDebug, "SSU: second peer test from Charlie. We are Alice"); i2p::context.SetStatus (eRouterStatusOK); m_Server.RemovePeerTest (nonce); } @@ -941,7 +941,7 @@ namespace transport } case ePeerTestParticipantBob: { - LogPrint (eLogDebug, "SSU peer test from Charlie. We are Bob"); + LogPrint (eLogDebug, "SSU: peer test from Charlie. We are Bob"); auto session = m_Server.GetPeerTestSession (nonce); // session with Alice from PeerTest if (session && session->m_State == eSessionStateEstablished) session->Send (PAYLOAD_TYPE_PEER_TEST, buf, len); // back to Alice @@ -950,7 +950,7 @@ namespace transport } case ePeerTestParticipantCharlie: { - LogPrint (eLogDebug, "SSU peer test from Alice. We are Charlie"); + LogPrint (eLogDebug, "SSU: peer test from Alice. We are Charlie"); SendPeerTest (nonce, senderEndpoint.address ().to_v4 ().to_ulong (), senderEndpoint.port (), introKey); // to Alice with her actual address m_Server.RemovePeerTest (nonce); // nonce has been used @@ -964,14 +964,14 @@ namespace transport // new test if (port) { - LogPrint (eLogDebug, "SSU peer test from Bob. We are Charlie"); + LogPrint (eLogDebug, "SSU: peer test from Bob. We are Charlie"); m_Server.NewPeerTest (nonce, ePeerTestParticipantCharlie); Send (PAYLOAD_TYPE_PEER_TEST, buf, len); // back to Bob SendPeerTest (nonce, be32toh (address), be16toh (port), introKey); // to Alice with her address received from Bob } else { - LogPrint (eLogDebug, "SSU peer test from Alice. We are Bob"); + LogPrint (eLogDebug, "SSU: peer test from Alice. We are Bob"); auto session = m_Server.GetRandomEstablishedV4Session (shared_from_this ()); // Charlie, TODO: implement v6 support if (session) { @@ -982,7 +982,7 @@ namespace transport } } else - LogPrint (eLogError, "SSU unexpected peer test"); + LogPrint (eLogError, "SSU: unexpected peer test"); } } } @@ -1045,7 +1045,7 @@ namespace transport void SSUSession::SendPeerTest () { // we are Alice - LogPrint (eLogDebug, "SSU sending peer test"); + LogPrint (eLogDebug, "SSU: sending peer test"); auto address = i2p::context.GetRouterInfo ().GetSSUAddress (); if (!address) { @@ -1072,7 +1072,7 @@ namespace transport // encrypt message with session key FillHeaderAndEncrypt (PAYLOAD_TYPE_DATA, buf, 48); Send (buf, 48); - LogPrint (eLogDebug, "SSU keep-alive sent"); + LogPrint (eLogDebug, "SSU: keep-alive sent"); ScheduleTermination (); } } @@ -1090,9 +1090,9 @@ namespace transport } catch (std::exception& ex) { - LogPrint (eLogError, "SSU send session destoriyed exception ", ex.what ()); + LogPrint (eLogError, "SSU: exception while send session destoriyed: ", ex.what ()); } - LogPrint (eLogDebug, "SSU session destroyed sent"); + LogPrint (eLogDebug, "SSU: session destroyed sent"); } } @@ -1104,7 +1104,7 @@ namespace transport if (paddingSize > 0) msgSize += (16 - paddingSize); if (msgSize > SSU_MTU_V4) { - LogPrint (eLogWarning, "SSU payload size ", msgSize, " exceeds MTU"); + LogPrint (eLogWarning, "SSU: payload size ", msgSize, " exceeds MTU"); return; } memcpy (buf + sizeof (SSUHeader), payload, len); From c3958bf042e0509dec24f464bd87302931d657c4 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 04:15:05 +0000 Subject: [PATCH 05/32] * sane log messages: NTCPSession.cpp --- NTCPSession.cpp | 82 ++++++++++++++++++++++++------------------------- 1 file changed, 41 insertions(+), 41 deletions(-) diff --git a/NTCPSession.cpp b/NTCPSession.cpp index 90733d73..f7d3b3d7 100644 --- a/NTCPSession.cpp +++ b/NTCPSession.cpp @@ -56,7 +56,7 @@ namespace transport nonZero++; if (nonZero - sharedKey > 32) { - LogPrint (eLogWarning, "First 32 bytes of shared key is all zeros. Ignored"); + LogPrint (eLogWarning, "NTCP: First 32 bytes of shared key is all zeros, ignored"); return; } } @@ -81,7 +81,7 @@ namespace transport m_SendQueue.clear (); m_NextMessage = nullptr; m_TerminationTimer.cancel (); - LogPrint (eLogInfo, "NTCP session terminated"); + LogPrint (eLogDebug, "NTCP: session terminated"); } } @@ -136,7 +136,7 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Couldn't send Phase 1 message: ", ecode.message ()); + LogPrint (eLogError, "NTCP: couldn't send Phase 1 message: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -152,7 +152,7 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Phase 1 read error: ", ecode.message ()); + LogPrint (eLogError, "NTCP: phase 1 read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -166,7 +166,7 @@ namespace transport { if ((m_Establisher->phase1.HXxorHI[i] ^ ident[i]) != digest[i]) { - LogPrint (eLogError, "Wrong ident"); + LogPrint (eLogError, "NTCP: phase 1 error: ident mismatch"); Terminate (); return; } @@ -207,7 +207,7 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Couldn't send Phase 2 message: ", ecode.message ()); + LogPrint (eLogError, "NTCP: Couldn't send Phase 2 message: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -223,7 +223,7 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Phase 2 read error: ", ecode.message (), ". Wrong ident assumed"); + LogPrint (eLogError, "NTCP: Phase 2 read error: ", ecode.message (), ". Wrong ident assumed"); if (ecode != boost::asio::error::operation_aborted) { // this RI is not valid @@ -251,7 +251,7 @@ namespace transport SHA256 (xy, 512, digest); if (memcmp(m_Establisher->phase2.encrypted.hxy, digest, 32)) { - LogPrint (eLogError, "Incorrect hash"); + LogPrint (eLogError, "NTCP: Phase 2 process error: incorrect hash"); transports.ReuseDHKeysPair (m_DHKeysPair); m_DHKeysPair = nullptr; Terminate (); @@ -299,7 +299,7 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Couldn't send Phase 3 message: ", ecode.message ()); + LogPrint (eLogError, "NTCP: Couldn't send Phase 3 message: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -319,7 +319,7 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Phase 3 read error: ", ecode.message ()); + LogPrint (eLogError, "NTCP: Phase 3 read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -331,7 +331,7 @@ namespace transport SetRemoteIdentity (std::make_shared (buf + 2, size)); if (m_Server.FindNTCPSession (m_RemoteIdentity->GetIdentHash ())) { - LogPrint (eLogError, "NTCP session already exists"); + LogPrint (eLogError, "NTCP: session already exists"); Terminate (); } size_t expectedSize = size + 2/*size*/ + 4/*timestamp*/ + m_RemoteIdentity->GetSignatureLen (); @@ -354,7 +354,7 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Phase 3 extra read error: ", ecode.message ()); + LogPrint (eLogError, "NTCP: Phase 3 extra read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -380,7 +380,7 @@ namespace transport s.Insert (tsB); // tsB if (!s.Verify (m_RemoteIdentity, buf)) { - LogPrint (eLogError, "signature verification failed"); + LogPrint (eLogError, "NTCP: signature verification failed"); Terminate (); return; } @@ -411,13 +411,13 @@ namespace transport { if (ecode) { - LogPrint (eLogWarning, "Couldn't send Phase 4 message: ", ecode.message ()); + LogPrint (eLogWarning, "NTCP: Couldn't send Phase 4 message: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } else { - LogPrint (eLogInfo, "NTCP server session from ", m_Socket.remote_endpoint (), " connected"); + LogPrint (eLogInfo, "NTCP: Server session from ", m_Socket.remote_endpoint (), " connected"); m_Server.AddNTCPSession (shared_from_this ()); Connected (); @@ -431,7 +431,7 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Phase 4 read error: ", ecode.message (), ". Check your clock"); + LogPrint (eLogError, "NTCP: Phase 4 read error: ", ecode.message (), ". Check your clock"); if (ecode != boost::asio::error::operation_aborted) { // this router doesn't like us @@ -453,11 +453,11 @@ namespace transport if (!s.Verify (m_RemoteIdentity, m_ReceiveBuffer)) { - LogPrint (eLogError, "signature verification failed"); + LogPrint (eLogError, "NTCP: Phase 4 process error: signature verification failed"); Terminate (); return; } - LogPrint (eLogInfo, "NTCP session to ", m_Socket.remote_endpoint (), " connected"); + LogPrint (eLogDebug, "NTCP: session to ", m_Socket.remote_endpoint (), " connected"); Connected (); m_ReceiveBufferOffset = 0; @@ -477,7 +477,7 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Read error: ", ecode.message ()); + LogPrint (eLogError, "NTCP: Read error: ", ecode.message ()); if (!m_NumReceivedBytes) m_Server.Ban (m_ConnectedFrom); //if (ecode != boost::asio::error::operation_aborted) Terminate (); @@ -519,7 +519,7 @@ namespace transport moreBytes = m_Socket.read_some (boost::asio::buffer (m_ReceiveBuffer + m_ReceiveBufferOffset, moreBytes)); if (ec) { - LogPrint (eLogError, "Read more bytes error: ", ec.message ()); + LogPrint (eLogError, "NTCP: Read more bytes error: ", ec.message ()); Terminate (); return; } @@ -542,7 +542,7 @@ namespace transport { if (!m_NextMessage) // new message, header expected { - // descrypt header and extract length + // decrypt header and extract length uint8_t buf[16]; m_Decryption.Decrypt (encrypted, buf); uint16_t dataSize = bufbe16toh (buf); @@ -551,7 +551,7 @@ namespace transport // new message if (dataSize > NTCP_MAX_MESSAGE_SIZE) { - LogPrint (eLogError, "NTCP data size ", dataSize, " exceeds max size"); + LogPrint (eLogError, "NTCP: data size ", dataSize, " exceeds max size"); return false; } auto msg = dataSize <= I2NP_MAX_SHORT_MESSAGE_SIZE - 2 ? NewI2NPShortMessage () : NewI2NPMessage (); @@ -564,7 +564,7 @@ namespace transport else { // timestamp - LogPrint ("Timestamp"); + LogPrint (eLogDebug, "NTCP: Timestamp"); return true; } } @@ -582,7 +582,7 @@ namespace transport if (!memcmp (m_NextMessage->buf + m_NextMessageOffset - 4, checksum, 4)) m_Handler.PutNextMessage (m_NextMessage); else - LogPrint (eLogWarning, "Incorrect adler checksum of NTCP message. Dropped"); + LogPrint (eLogWarning, "NTCP: Incorrect adler checksum of message, dropped"); m_NextMessage = nullptr; } return true; @@ -604,7 +604,7 @@ namespace transport { // regular I2NP if (msg->offset < 2) - LogPrint (eLogError, "Malformed I2NP message"); // TODO: + LogPrint (eLogError, "NTCP: Malformed I2NP message"); // TODO: sendBuffer = msg->GetBuffer () - 2; len = msg->GetLength (); htobe16buf (sendBuffer, len); @@ -644,7 +644,7 @@ namespace transport m_IsSending = false; if (ecode) { - LogPrint (eLogWarning, "Couldn't send msgs: ", ecode.message ()); + LogPrint (eLogWarning, "NTCP: Couldn't send msgs: ", ecode.message ()); // we shouldn't call Terminate () here, because HandleReceive takes care // TODO: 'delete this' statement in Terminate () must be eliminated later // Terminate (); @@ -699,7 +699,7 @@ namespace transport { if (ecode != boost::asio::error::operation_aborted) { - LogPrint ("No activity fo ", NTCP_TERMINATION_TIMEOUT, " seconds"); + LogPrint (eLogWarning, "NTCP: No activity fo ", NTCP_TERMINATION_TIMEOUT, " seconds"); //Terminate (); m_Socket.close ();// invoke Terminate () from HandleReceive } @@ -732,7 +732,7 @@ namespace transport m_NTCPAcceptor = new boost::asio::ip::tcp::acceptor (m_Service, boost::asio::ip::tcp::endpoint(boost::asio::ip::tcp::v4(), address.port)); - LogPrint (eLogInfo, "Start listening TCP port ", address.port); + LogPrint (eLogInfo, "NTCP: Start listening TCP port ", address.port); auto conn = std::make_shared(*this); m_NTCPAcceptor->async_accept(conn->GetSocket (), std::bind (&NTCPServer::HandleAccept, this, conn, std::placeholders::_1)); @@ -745,7 +745,7 @@ namespace transport m_NTCPV6Acceptor->bind (boost::asio::ip::tcp::endpoint(boost::asio::ip::tcp::v6(), address.port)); m_NTCPV6Acceptor->listen (); - LogPrint (eLogInfo, "Start listening V6 TCP port ", address.port); + LogPrint (eLogInfo, "NTCP: Start listening V6 TCP port ", address.port); auto conn = std::make_shared (*this); m_NTCPV6Acceptor->async_accept(conn->GetSocket (), std::bind (&NTCPServer::HandleAcceptV6, this, conn, std::placeholders::_1)); @@ -788,7 +788,7 @@ namespace transport } catch (std::exception& ex) { - LogPrint ("NTCP server: ", ex.what ()); + LogPrint (eLogError, "NTCP: runtime exception: ", ex.what ()); } } } @@ -800,7 +800,7 @@ namespace transport auto it = m_NTCPSessions.find (ident); if (it != m_NTCPSessions.end ()) { - LogPrint (eLogWarning, "NTCP session to ", ident.ToBase64 (), " already exists"); + LogPrint (eLogWarning, "NTCP: session to ", ident.ToBase64 (), " already exists"); return false; } m_NTCPSessions.insert (std::pair >(ident, session)); @@ -829,14 +829,14 @@ namespace transport auto ep = conn->GetSocket ().remote_endpoint(ec); if (!ec) { - LogPrint (eLogInfo, "Connected from ", ep); + LogPrint (eLogDebug, "NTCP: Connected from ", ep); auto it = m_BanList.find (ep.address ()); if (it != m_BanList.end ()) { uint32_t ts = i2p::util::GetSecondsSinceEpoch (); if (ts < it->second) { - LogPrint (eLogInfo, ep.address (), " is banned for ", it->second - ts, " more seconds"); + LogPrint (eLogWarning, "NTCP: ", ep.address (), " is banned for ", it->second - ts, " more seconds"); conn = nullptr; } else @@ -846,7 +846,7 @@ namespace transport conn->ServerLogin (); } else - LogPrint (eLogError, "Connected from error ", ec.message ()); + LogPrint (eLogError, "NTCP: Connected from error ", ec.message ()); } @@ -866,14 +866,14 @@ namespace transport auto ep = conn->GetSocket ().remote_endpoint(ec); if (!ec) { - LogPrint (eLogInfo, "Connected from ", ep); + LogPrint (eLogDebug, "NTCP: Connected from ", ep); auto it = m_BanList.find (ep.address ()); if (it != m_BanList.end ()) { uint32_t ts = i2p::util::GetSecondsSinceEpoch (); if (ts < it->second) { - LogPrint (eLogInfo, ep.address (), " is banned for ", it->second - ts, " more seconds"); + LogPrint (eLogWarning, "NTCP: ", ep.address (), " is banned for ", it->second - ts, " more seconds"); conn = nullptr; } else @@ -883,7 +883,7 @@ namespace transport conn->ServerLogin (); } else - LogPrint (eLogError, "Connected from error ", ec.message ()); + LogPrint (eLogError, "NTCP: Connected from error ", ec.message ()); } if (error != boost::asio::error::operation_aborted) @@ -896,7 +896,7 @@ namespace transport void NTCPServer::Connect (const boost::asio::ip::address& address, int port, std::shared_ptr conn) { - LogPrint (eLogInfo, "Connecting to ", address ,":", port); + LogPrint (eLogDebug, "NTCP: Connecting to ", address ,":", port); m_Service.post([=]() { if (this->AddNTCPSession (conn)) @@ -909,14 +909,14 @@ namespace transport { if (ecode) { - LogPrint (eLogError, "Connect error: ", ecode.message ()); + LogPrint (eLogError, "NTCP: Connect error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) i2p::data::netdb.SetUnreachable (conn->GetRemoteIdentity ()->GetIdentHash (), true); conn->Terminate (); } else { - LogPrint (eLogInfo, "Connected to ", conn->GetSocket ().remote_endpoint ()); + LogPrint (eLogDebug, "NTCP: Connected to ", conn->GetSocket ().remote_endpoint ()); if (conn->GetSocket ().local_endpoint ().protocol () == boost::asio::ip::tcp::v6()) // ipv6 context.UpdateNTCPV6Address (conn->GetSocket ().local_endpoint ().address ()); conn->ClientLogin (); @@ -927,7 +927,7 @@ namespace transport { uint32_t ts = i2p::util::GetSecondsSinceEpoch (); m_BanList[addr] = ts + NTCP_BAN_EXPIRATION_TIMEOUT; - LogPrint (eLogInfo, addr, " has been banned for ", NTCP_BAN_EXPIRATION_TIMEOUT, " seconds"); + LogPrint (eLogWarning, "NTCP: ", addr, " has been banned for ", NTCP_BAN_EXPIRATION_TIMEOUT, " seconds"); } } } From 3156f7dacd6839d1aedcae239ac7d68e43ad7623 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 06:20:06 +0000 Subject: [PATCH 06/32] * sane log messages: Tunnel.cpp --- Tunnel.cpp | 28 ++++++++++++++-------------- 1 file changed, 14 insertions(+), 14 deletions(-) diff --git a/Tunnel.cpp b/Tunnel.cpp index 8e5510f1..c7d6573e 100644 --- a/Tunnel.cpp +++ b/Tunnel.cpp @@ -92,7 +92,7 @@ namespace tunnel bool Tunnel::HandleTunnelBuildResponse (uint8_t * msg, size_t len) { - LogPrint ("TunnelBuildResponse ", (int)msg[0], " records."); + LogPrint (eLogDebug, "Tunnel: TunnelBuildResponse ", (int)msg[0], " records."); i2p::crypto::CBCDecryption decryption; TunnelHopConfig * hop = m_Config->GetLastHop (); @@ -111,7 +111,7 @@ namespace tunnel decryption.Decrypt(record, TUNNEL_BUILD_RECORD_SIZE, record); } else - LogPrint ("Tunnel hop index ", idx, " is out of range"); + LogPrint (eLogWarning, "Tunnel: hop index ", idx, " is out of range"); hop1 = hop1->prev; } hop = hop->prev; @@ -123,7 +123,7 @@ namespace tunnel { const uint8_t * record = msg + 1 + hop->recordIndex*TUNNEL_BUILD_RECORD_SIZE; uint8_t ret = record[BUILD_RESPONSE_RECORD_RET_OFFSET]; - LogPrint ("Ret code=", (int)ret); + LogPrint (eLogDebug, "Tunnel: Build response ret code=", (int)ret); auto profile = i2p::data::netdb.FindRouterProfile (hop->ident->GetIdentHash ()); if (profile) profile->TunnelBuildResponse (ret); @@ -163,7 +163,7 @@ namespace tunnel void Tunnel::SendTunnelDataMsg (std::shared_ptr msg) { - LogPrint (eLogInfo, "Can't send I2NP messages without delivery instructions"); + LogPrint (eLogInfo, "Tunnel: Can't send I2NP messages without delivery instructions"); } std::vector > Tunnel::GetPeers () const @@ -442,7 +442,7 @@ namespace tunnel HandleI2NPMessage (msg->GetBuffer (), msg->GetLength ()); break; default: - LogPrint (eLogError, "Unexpected messsage type ", (int)typeID); + LogPrint (eLogError, "Tunnel: Unexpected messsage type ", (int)typeID); } msg = m_Queue.Get (); @@ -466,7 +466,7 @@ namespace tunnel } catch (std::exception& ex) { - LogPrint ("Tunnels: ", ex.what ()); + LogPrint (eLogError, "Tunnel: runtime exception: ", ex.what ()); } } } @@ -521,7 +521,7 @@ namespace tunnel case eTunnelStatePending: if (ts > tunnel->GetCreationTime () + TUNNEL_CREATION_TIMEOUT) { - LogPrint ("Pending tunnel build request ", it->first, " timeout. Deleted"); + LogPrint (eLogError, "Tunnel: Pending build request ", it->first, " timeout, deleted"); // update stats auto config = tunnel->GetTunnelConfig (); if (config) @@ -546,7 +546,7 @@ namespace tunnel it++; break; case eTunnelStateBuildFailed: - LogPrint ("Pending tunnel build request ", it->first, " failed. Deleted"); + LogPrint (eLogError, "Tunnel: Pending build request ", it->first, " failed, deleted"); it = pendingTunnels.erase (it); m_NumFailedTunnelCreations++; break; @@ -571,7 +571,7 @@ namespace tunnel auto tunnel = *it; if (ts > tunnel->GetCreationTime () + TUNNEL_EXPIRATION_TIMEOUT) { - LogPrint ("Tunnel ", tunnel->GetTunnelID (), " expired"); + LogPrint (eLogDebug, "Tunnel: ", tunnel->GetTunnelID (), " expired"); auto pool = tunnel->GetTunnelPool (); if (pool) pool->TunnelExpired (tunnel); @@ -602,7 +602,7 @@ namespace tunnel auto inboundTunnel = GetNextInboundTunnel (); auto router = i2p::data::netdb.GetRandomRouter (); if (!inboundTunnel || !router) return; - LogPrint ("Creating one hop outbound tunnel..."); + LogPrint (eLogDebug, "Creating one hop outbound tunnel"); CreateTunnel ( std::make_shared (std::vector > { router->GetRouterIdentity () }, inboundTunnel->GetNextTunnelID (), inboundTunnel->GetNextIdentHash ()) @@ -619,7 +619,7 @@ namespace tunnel auto tunnel = it->second; if (ts > tunnel->GetCreationTime () + TUNNEL_EXPIRATION_TIMEOUT) { - LogPrint ("Tunnel ", tunnel->GetTunnelID (), " expired"); + LogPrint (eLogDebug, "Tunnel: ", tunnel->GetTunnelID (), " expired"); auto pool = tunnel->GetTunnelPool (); if (pool) pool->TunnelExpired (tunnel); @@ -647,7 +647,7 @@ namespace tunnel if (m_InboundTunnels.empty ()) { - LogPrint ("Creating zero hops inbound tunnel..."); + LogPrint (eLogDebug, "Creating zero hops inbound tunnel..."); CreateZeroHopsInboundTunnel (); if (!m_ExploratoryPool) { @@ -661,7 +661,7 @@ namespace tunnel { // trying to create one more inbound tunnel auto router = i2p::data::netdb.GetRandomRouter (); - LogPrint ("Creating one hop inbound tunnel..."); + LogPrint (eLogDebug, "Creating one hop inbound tunnel..."); CreateTunnel ( std::make_shared (std::vector > { router->GetRouterIdentity () }) ); @@ -676,7 +676,7 @@ namespace tunnel if (ts > it->second->GetCreationTime () + TUNNEL_EXPIRATION_TIMEOUT) { auto tmp = it->second; - LogPrint ("Transit tunnel ", tmp->GetTunnelID (), " expired"); + LogPrint (eLogDebug, "Transit tunnel ", tmp->GetTunnelID (), " expired"); { std::unique_lock l(m_TransitTunnelsMutex); it = m_TransitTunnels.erase (it); From a0fe02a5605e48880f6bdc99b47d4659b93242da Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 06:27:35 +0000 Subject: [PATCH 07/32] * sane log messages: BOB.cpp --- BOB.cpp | 26 +++++++++++++------------- 1 file changed, 13 insertions(+), 13 deletions(-) diff --git a/BOB.cpp b/BOB.cpp index 38777092..af1fb19a 100644 --- a/BOB.cpp +++ b/BOB.cpp @@ -61,7 +61,7 @@ namespace client std::shared_ptr receiver) { if (ecode) - LogPrint ("BOB inbound tunnel read error: ", ecode.message ()); + LogPrint (eLogError, "BOB: inbound tunnel read error: ", ecode.message ()); else { receiver->bufferOffset += bytes_transferred; @@ -76,7 +76,7 @@ namespace client i2p::data::IdentHash ident; if (!context.GetAddressBook ().GetIdentHash (receiver->buffer, ident)) { - LogPrint (eLogError, "BOB address ", receiver->buffer, " not found"); + LogPrint (eLogError, "BOB: address ", receiver->buffer, " not found"); return; } auto leaseSet = GetLocalDestination ()->FindLeaseSet (ident); @@ -92,7 +92,7 @@ namespace client if (receiver->bufferOffset < BOB_COMMAND_BUFFER_SIZE) ReceiveAddress (receiver); else - LogPrint ("BOB missing inbound address "); + LogPrint (eLogError, "BOB: missing inbound address"); } } } @@ -102,12 +102,12 @@ namespace client if (leaseSet) CreateConnection (receiver, leaseSet); else - LogPrint ("LeaseSet for BOB inbound destination not found"); + LogPrint (eLogError, "BOB: LeaseSet for inbound destination not found"); } void BOBI2PInboundTunnel::CreateConnection (std::shared_ptr receiver, std::shared_ptr leaseSet) { - LogPrint ("New BOB inbound connection"); + LogPrint (eLogDebug, "BOB: New inbound connection"); auto connection = std::make_shared(this, receiver->socket, leaseSet); AddHandler (connection); connection->I2PConnect (receiver->data, receiver->dataLen); @@ -135,7 +135,7 @@ namespace client if (localDestination) localDestination->AcceptStreams (std::bind (&BOBI2POutboundTunnel::HandleAccept, this, std::placeholders::_1)); else - LogPrint ("Local destination not set for server tunnel"); + LogPrint (eLogError, "BOB: Local destination not set for server tunnel"); } void BOBI2POutboundTunnel::HandleAccept (std::shared_ptr stream) @@ -229,7 +229,7 @@ namespace client { if (ecode) { - LogPrint ("BOB command channel read error: ", ecode.message ()); + LogPrint (eLogError, "BOB: command channel read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -256,7 +256,7 @@ namespace client (this->*(it->second))(operand, eol - operand); else { - LogPrint (eLogError, "BOB unknown command ", m_ReceiveBuffer); + LogPrint (eLogError, "BOB: unknown command ", m_ReceiveBuffer); SendReplyError ("unknown command"); } @@ -269,7 +269,7 @@ namespace client m_ReceiveBufferOffset = size; else { - LogPrint (eLogError, "Malformed input of the BOB command channel"); + LogPrint (eLogError, "BOB: Malformed input of the command channel"); Terminate (); } } @@ -288,7 +288,7 @@ namespace client { if (ecode) { - LogPrint ("BOB command channel send error: ", ecode.message ()); + LogPrint (eLogError, "BOB: command channel send error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -589,7 +589,7 @@ namespace client } catch (std::exception& ex) { - LogPrint (eLogError, "BOB: ", ex.what ()); + LogPrint (eLogError, "BOB: runtime exception: ", ex.what ()); } } } @@ -632,11 +632,11 @@ namespace client if (!ecode) { - LogPrint (eLogInfo, "New BOB command connection from ", session->GetSocket ().remote_endpoint ()); + LogPrint (eLogInfo, "BOB: New command connection from ", session->GetSocket ().remote_endpoint ()); session->SendVersion (); } else - LogPrint (eLogError, "BOB accept error: ", ecode.message ()); + LogPrint (eLogError, "BOB: accept error: ", ecode.message ()); } } } From 0859cf30f818a5e4b6681d8bd07878b367514876 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 06:35:39 +0000 Subject: [PATCH 08/32] * sane log messages: UPnP.cpp --- UPnP.cpp | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/UPnP.cpp b/UPnP.cpp index 6773b514..f8c038ff 100644 --- a/UPnP.cpp +++ b/UPnP.cpp @@ -46,7 +46,7 @@ template F GetKnownProcAddressImpl(M hmod, const char *name, F) { auto proc = reinterpret_cast(dlsym(hmod, name)); if (!proc) { - LogPrint("Error resolving ", name, " from UPNP library. This often happens if there is version mismatch!"); + LogPrint(eLogError, "UPnP: Error resolving ", name, " from library, version mismatch?"); } return proc; } @@ -83,7 +83,7 @@ namespace transport #endif if (m_Module == NULL) { - LogPrint ("Error loading UPNP library. This often happens if there is version mismatch!"); + LogPrint (eLogError, "UPnP: Error loading UPNP library, version mismatch?"); return; } else @@ -144,20 +144,20 @@ namespace transport r = UPNP_GetExternalIPAddressFunc (m_upnpUrls.controlURL, m_upnpData.first.servicetype, m_externalIPAddress); if(r != UPNPCOMMAND_SUCCESS) { - LogPrint ("UPnP: UPNP_GetExternalIPAddress () returned ", r); + LogPrint (eLogError, "UPnP: UPNP_GetExternalIPAddress () returned ", r); return; } else { if (m_externalIPAddress[0]) { - LogPrint ("UPnP: ExternalIPAddress = ", m_externalIPAddress); + LogPrint (eLogInfo, "UPnP: ExternalIPAddress = ", m_externalIPAddress); i2p::context.UpdateAddress (boost::asio::ip::address::from_string (m_externalIPAddress)); return; } else { - LogPrint ("UPnP: GetExternalIPAddress failed."); + LogPrint (eLogError, "UPnP: GetExternalIPAddress failed."); return; } } @@ -189,12 +189,12 @@ namespace transport #endif if (r!=UPNPCOMMAND_SUCCESS) { - LogPrint ("AddPortMapping (", strPort.c_str () ,", ", strPort.c_str () ,", ", m_NetworkAddr, ") failed with code ", r); + LogPrint (eLogError, "UPnP: AddPortMapping (", strPort.c_str () ,", ", strPort.c_str () ,", ", m_NetworkAddr, ") failed with code ", r); return; } else { - LogPrint ("UPnP Port Mapping successful. (", m_NetworkAddr ,":", strPort.c_str(), " type ", strType.c_str () ," -> ", m_externalIPAddress ,":", strPort.c_str() ,")"); + LogPrint (eLogDebug, "UPnP: Port Mapping successful. (", m_NetworkAddr ,":", strPort.c_str(), " type ", strType.c_str () ," -> ", m_externalIPAddress ,":", strPort.c_str() ,")"); return; } std::this_thread::sleep_for(std::chrono::minutes(20)); // c++11 @@ -224,7 +224,7 @@ namespace transport } int r = 0; r = UPNP_DeletePortMappingFunc (m_upnpUrls.controlURL, m_upnpData.first.servicetype, strPort.c_str (), strType.c_str (), 0); - LogPrint ("UPNP_DeletePortMapping() returned : ", r, "\n"); + LogPrint (eLogError, "UPnP: DeletePortMapping() returned : ", r, "\n"); } void UPnP::Close () From 89a0a94f3ec262d405445ca652879faf50bebd0f Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 06:50:12 +0000 Subject: [PATCH 09/32] * sane log messages: SAM.cpp --- SAM.cpp | 78 ++++++++++++++++++++++++++++----------------------------- 1 file changed, 39 insertions(+), 39 deletions(-) diff --git a/SAM.cpp b/SAM.cpp index 0c0cb714..a20de13d 100644 --- a/SAM.cpp +++ b/SAM.cpp @@ -78,7 +78,7 @@ namespace client { if (ecode) { - LogPrint ("SAM handshake read error: ", ecode.message ()); + LogPrint (eLogError, "SAM: handshake read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -88,7 +88,7 @@ namespace client char * eol = (char *)memchr (m_Buffer, '\n', bytes_transferred); if (eol) *eol = 0; - LogPrint ("SAM handshake ", m_Buffer); + LogPrint (eLogDebug, "SAM: handshake ", m_Buffer); char * separator = strchr (m_Buffer, ' '); if (separator) { @@ -127,7 +127,7 @@ namespace client } else { - LogPrint ("SAM handshake mismatch"); + LogPrint (eLogError, "SAM: handshake mismatch"); Terminate (); } } @@ -137,7 +137,7 @@ namespace client { if (ecode) { - LogPrint ("SAM handshake reply send error: ", ecode.message ()); + LogPrint (eLogError, "SAM: handshake reply send error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -168,7 +168,7 @@ namespace client { if (ecode) { - LogPrint ("SAM reply send error: ", ecode.message ()); + LogPrint (eLogError, "SAM: reply send error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -185,7 +185,7 @@ namespace client { if (ecode) { - LogPrint ("SAM read error: ", ecode.message ()); + LogPrint (eLogError, "SAM: read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -240,19 +240,19 @@ namespace client } else { - LogPrint (eLogError, "SAM unexpected message ", m_Buffer); + LogPrint (eLogError, "SAM: unexpected message ", m_Buffer); Terminate (); } } else { - LogPrint (eLogError, "SAM malformed message ", m_Buffer); + LogPrint (eLogError, "SAM: malformed message ", m_Buffer); Terminate (); } } else { - LogPrint (eLogWarning, "SAM incomplete message ", bytes_transferred); + LogPrint (eLogWarning, "SAM: incomplete message ", bytes_transferred); m_BufferOffset = bytes_transferred; // try to receive remaining message Receive (); @@ -262,7 +262,7 @@ namespace client void SAMSocket::ProcessSessionCreate (char * buf, size_t len) { - LogPrint ("SAM session create: ", buf); + LogPrint (eLogDebug, "SAM: session create: ", buf); std::map params; ExtractParams (buf, params); std::string& style = params[SAM_PARAM_STYLE]; @@ -333,7 +333,7 @@ namespace client void SAMSocket::ProcessStreamConnect (char * buf, size_t len) { - LogPrint (eLogDebug, "SAM stream connect: ", buf); + LogPrint (eLogDebug, "SAM: stream connect: ", buf); std::map params; ExtractParams (buf, params); std::string& id = params[SAM_PARAM_ID]; @@ -382,14 +382,14 @@ namespace client Connect (leaseSet); else { - LogPrint ("SAM destination to connect not found"); + LogPrint (eLogError, "SAM: destination to connect not found"); SendMessageReply (SAM_STREAM_STATUS_CANT_REACH_PEER, strlen(SAM_STREAM_STATUS_CANT_REACH_PEER), true); } } void SAMSocket::ProcessStreamAccept (char * buf, size_t len) { - LogPrint (eLogDebug, "SAM stream accept: ", buf); + LogPrint (eLogDebug, "SAM: stream accept: ", buf); std::map params; ExtractParams (buf, params); std::string& id = params[SAM_PARAM_ID]; @@ -415,7 +415,7 @@ namespace client size_t SAMSocket::ProcessDatagramSend (char * buf, size_t len, const char * data) { - LogPrint (eLogDebug, "SAM datagram send: ", buf, " ", len); + LogPrint (eLogDebug, "SAM: datagram send: ", buf, " ", len); std::map params; ExtractParams (buf, params); size_t size = boost::lexical_cast(params[SAM_PARAM_SIZE]), offset = data - buf; @@ -431,14 +431,14 @@ namespace client d->SendDatagramTo ((const uint8_t *)data, size, dest.GetIdentHash ()); } else - LogPrint (eLogError, "SAM missing datagram destination"); + LogPrint (eLogError, "SAM: missing datagram destination"); } else - LogPrint (eLogError, "SAM session is not created from DATAGRAM SEND"); + LogPrint (eLogError, "SAM: session is not created from DATAGRAM SEND"); } else { - LogPrint (eLogWarning, "SAM sent datagram size ", size, " exceeds buffer ", len - offset); + LogPrint (eLogWarning, "SAM: sent datagram size ", size, " exceeds buffer ", len - offset); return 0; // try to receive more } return offset + size; @@ -446,7 +446,7 @@ namespace client void SAMSocket::ProcessDestGenerate () { - LogPrint (eLogDebug, "SAM dest generate"); + LogPrint (eLogDebug, "SAM: dest generate"); auto keys = i2p::data::PrivateKeys::CreateRandomKeys (); #ifdef _MSC_VER size_t len = sprintf_s (m_Buffer, SAM_SOCKET_BUFFER_SIZE, SAM_DEST_REPLY, @@ -460,7 +460,7 @@ namespace client void SAMSocket::ProcessNamingLookup (char * buf, size_t len) { - LogPrint (eLogDebug, "SAM naming lookup: ", buf); + LogPrint (eLogDebug, "SAM: naming lookup: ", buf); std::map params; ExtractParams (buf, params); std::string& name = params[SAM_PARAM_NAME]; @@ -483,7 +483,7 @@ namespace client } else { - LogPrint ("SAM naming failed. Unknown address ", name); + LogPrint (eLogError, "SAM: naming failed, unknown address ", name); #ifdef _MSC_VER size_t len = sprintf_s (m_Buffer, SAM_SOCKET_BUFFER_SIZE, SAM_NAMING_REPLY_INVALID_KEY, name.c_str()); #else @@ -502,7 +502,7 @@ namespace client } else { - LogPrint (eLogInfo, "SAM naming lookup failed. LeaseSet for ", ident.ToBase32 (), " not found"); + LogPrint (eLogError, "SAM: naming lookup failed. LeaseSet for ", ident.ToBase32 (), " not found"); #ifdef _MSC_VER size_t len = sprintf_s (m_Buffer, SAM_SOCKET_BUFFER_SIZE, SAM_NAMING_REPLY_INVALID_KEY, context.GetAddressBook ().ToAddress (ident).c_str()); @@ -548,7 +548,7 @@ namespace client { if (m_BufferOffset >= SAM_SOCKET_BUFFER_SIZE) { - LogPrint (eLogError, "Buffer is full. Terminate"); + LogPrint (eLogError, "SAM: Buffer is full, terminate"); Terminate (); return; } @@ -561,7 +561,7 @@ namespace client { if (ecode) { - LogPrint ("SAM read error: ", ecode.message ()); + LogPrint (eLogError, "SAM: read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -595,7 +595,7 @@ namespace client { if (ecode) { - LogPrint ("SAM stream read error: ", ecode.message ()); + LogPrint (eLogError, "SAM: stream read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -610,7 +610,7 @@ namespace client { if (ecode) { - LogPrint ("SAM socket write error: ", ecode.message ()); + LogPrint (eLogError, "SAM: socket write error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -622,7 +622,7 @@ namespace client { if (stream) { - LogPrint ("SAM incoming I2P connection for session ", m_ID); + LogPrint (eLogDebug, "SAM: incoming I2P connection for session ", m_ID); m_Stream = stream; context.GetAddressBook ().InsertAddress (stream->GetRemoteIdentity ()); auto session = m_Owner.FindSession (m_ID); @@ -642,12 +642,12 @@ namespace client I2PReceive (); } else - LogPrint (eLogInfo, "SAM I2P acceptor has been reset"); + LogPrint (eLogWarning, "SAM: I2P acceptor has been reset"); } void SAMSocket::HandleI2PDatagramReceive (const i2p::data::IdentityEx& from, uint16_t fromPort, uint16_t toPort, const uint8_t * buf, size_t len) { - LogPrint (eLogDebug, "SAM datagram received ", len); + LogPrint (eLogDebug, "SAM: datagram received ", len); auto base64 = from.ToBase64 (); #ifdef _MSC_VER size_t l = sprintf_s ((char *)m_StreamBuffer, SAM_SOCKET_BUFFER_SIZE, SAM_DATAGRAM_RECEIVED, base64.c_str (), len); @@ -661,7 +661,7 @@ namespace client std::bind (&SAMSocket::HandleWriteI2PData, shared_from_this (), std::placeholders::_1)); } else - LogPrint (eLogWarning, "SAM received datagram size ", len," exceeds buffer"); + LogPrint (eLogWarning, "SAM: received datagram size ", len," exceeds buffer"); } SAMSession::SAMSession (std::shared_ptr dest): @@ -733,7 +733,7 @@ namespace client } catch (std::exception& ex) { - LogPrint ("SAM: ", ex.what ()); + LogPrint (eLogError, "SAM: runtime exception: ", ex.what ()); } } } @@ -753,14 +753,14 @@ namespace client auto ep = socket->GetSocket ().remote_endpoint (ec); if (!ec) { - LogPrint ("New SAM connection from ", ep); + LogPrint (eLogDebug, "SAM: new connection from ", ep); socket->ReceiveHandshake (); } else - LogPrint (eLogError, "SAM connection from error ", ec.message ()); + LogPrint (eLogError, "SAM: incoming connection error ", ec.message ()); } else - LogPrint ("SAM accept error: ", ecode.message ()); + LogPrint (eLogError, "SAM: accept error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Accept (); @@ -794,7 +794,7 @@ namespace client std::unique_lock l(m_SessionsMutex); auto ret = m_Sessions.insert (std::pair(id, new SAMSession (localDestination))); if (!ret.second) - LogPrint ("Session ", id, " already exists"); + LogPrint (eLogWarning, "SAM: Session ", id, " already exists"); return ret.first->second; } return nullptr; @@ -839,7 +839,7 @@ namespace client char * eol = strchr ((char *)m_DatagramReceiveBuffer, '\n'); *eol = 0; eol++; size_t payloadLen = bytes_transferred - ((uint8_t *)eol - m_DatagramReceiveBuffer); - LogPrint ("SAM datagram received ", m_DatagramReceiveBuffer," size=", payloadLen); + LogPrint (eLogDebug, "SAM: datagram received ", m_DatagramReceiveBuffer," size=", payloadLen); char * sessionID = strchr ((char *)m_DatagramReceiveBuffer, ' '); if (sessionID) { @@ -857,17 +857,17 @@ namespace client SendDatagramTo ((uint8_t *)eol, payloadLen, dest.GetIdentHash ()); } else - LogPrint ("Session ", sessionID, " not found"); + LogPrint (eLogError, "SAM: Session ", sessionID, " not found"); } else - LogPrint ("Missing destination key"); + LogPrint (eLogError, "SAM: Missing destination key"); } else - LogPrint ("Missing sessionID"); + LogPrint (eLogError, "SAM: Missing sessionID"); ReceiveDatagram (); } else - LogPrint ("SAM datagram receive error: ", ecode.message ()); + LogPrint (eLogError, "SAM: datagram receive error: ", ecode.message ()); } } } From 18fad9c9d9c34ba90b60d6137184d1b2ac6a0b7d Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 06:59:43 +0000 Subject: [PATCH 10/32] * sane log messages: Garlic.cpp --- Garlic.cpp | 46 +++++++++++++++++++++++----------------------- 1 file changed, 23 insertions(+), 23 deletions(-) diff --git a/Garlic.cpp b/Garlic.cpp index c94139e0..0008e25e 100644 --- a/Garlic.cpp +++ b/Garlic.cpp @@ -61,7 +61,7 @@ namespace garlic if (msgID == m_LeaseSetUpdateMsgID) { m_LeaseSetUpdateStatus = eLeaseSetUpToDate; - LogPrint (eLogInfo, "LeaseSet update confirmed"); + LogPrint (eLogInfo, "Garlic: LeaseSet update confirmed"); } else CleanupExpiredTags (); @@ -139,10 +139,10 @@ namespace garlic // create message if (!tagFound) // new session { - LogPrint ("No garlic tags available. Use ElGamal"); + LogPrint (eLogWarning, "Garlic: No tags available. Use ElGamal"); if (!m_Destination) { - LogPrint ("Can't use ElGamal for unknown destination"); + LogPrint (eLogError, "Garlic: Can't use ElGamal for unknown destination"); return nullptr; } // create ElGamal block @@ -237,7 +237,7 @@ namespace garlic m_Owner->DeliveryStatusSent (shared_from_this (), msgID); } else - LogPrint ("DeliveryStatus clove was not created"); + LogPrint (eLogWarning, "Garlic: DeliveryStatus clove was not created"); } // attach LeaseSet if (m_LeaseSetUpdateStatus == eLeaseSetUpdated) @@ -337,10 +337,10 @@ namespace garlic size += 3; } else - LogPrint (eLogError, "No inbound tunnels in the pool for DeliveryStatus"); + LogPrint (eLogError, "Garlic: No inbound tunnels in the pool for DeliveryStatus"); } else - LogPrint ("Missing local LeaseSet"); + LogPrint (eLogWarning, "Garlic: Missing local LeaseSet"); return size; } @@ -372,7 +372,7 @@ namespace garlic uint32_t length = bufbe32toh (buf); if (length > msg->GetLength ()) { - LogPrint (eLogError, "Garlic message length ", length, " exceeds I2NP message length ", msg->GetLength ()); + LogPrint (eLogWarning, "Garlic: message length ", length, " exceeds I2NP message length ", msg->GetLength ()); return; } buf += 4; // length @@ -389,7 +389,7 @@ namespace garlic HandleAESBlock (buf + 32, length - 32, it->second, msg->from); } else - LogPrint (eLogError, "Garlic message length ", length, " is less than 32 bytes"); + LogPrint (eLogWarning, "Garlic: message length ", length, " is less than 32 bytes"); m_Tags.erase (it); // tag might be used only once } else @@ -407,7 +407,7 @@ namespace garlic HandleAESBlock (buf + 514, length - 514, decryption, msg->from); } else - LogPrint (eLogError, "Failed to decrypt garlic"); + LogPrint (eLogError, "Garlic: Failed to decrypt message"); } // cleanup expired tags @@ -427,7 +427,7 @@ namespace garlic else it++; } - LogPrint (numExpiredTags, " tags expired for ", GetIdentHash().ToBase64 ()); + LogPrint (eLogDebug, "Garlic: ", numExpiredTags, " tags expired for ", GetIdentHash().ToBase64 ()); } m_LastTagsCleanupTime = ts; } @@ -442,7 +442,7 @@ namespace garlic { if (tagCount*32 > len) { - LogPrint (eLogError, "Tag count ", tagCount, " exceeds length ", len); + LogPrint (eLogError, "Garlic: Tag count ", tagCount, " exceeds length ", len); return ; } uint32_t ts = i2p::util::GetSecondsSinceEpoch (); @@ -454,7 +454,7 @@ namespace garlic uint32_t payloadSize = bufbe32toh (buf); if (payloadSize > len) { - LogPrint (eLogError, "Unexpected payload size ", payloadSize); + LogPrint (eLogError, "Garlic: Unexpected payload size ", payloadSize); return; } buf += 4; @@ -469,7 +469,7 @@ namespace garlic SHA256 (buf, payloadSize, digest); if (memcmp (payloadHash, digest, 32)) // payload hash doesn't match { - LogPrint ("Wrong payload hash"); + LogPrint (eLogError, "Garlic: wrong payload hash"); return; } HandleGarlicPayload (buf, payloadSize, from); @@ -479,7 +479,7 @@ namespace garlic { const uint8_t * buf1 = buf; int numCloves = buf[0]; - LogPrint (numCloves," cloves"); + LogPrint (eLogDebug, "Garlic: ", numCloves," cloves"); buf++; for (int i = 0; i < numCloves; i++) { @@ -489,24 +489,24 @@ namespace garlic if (flag & 0x80) // encrypted? { // TODO: implement - LogPrint ("Clove encrypted"); + LogPrint (eLogWarning, "Garlic: clove encrypted"); buf += 32; } GarlicDeliveryType deliveryType = (GarlicDeliveryType)((flag >> 5) & 0x03); switch (deliveryType) { case eGarlicDeliveryTypeLocal: - LogPrint ("Garlic type local"); + LogPrint (eLogDebug, "Garlic: type local"); HandleI2NPMessage (buf, len, from); break; case eGarlicDeliveryTypeDestination: - LogPrint ("Garlic type destination"); + LogPrint (eLogDebug, "Garlic: type destination"); buf += 32; // destination. check it later or for multiple destinations HandleI2NPMessage (buf, len, from); break; case eGarlicDeliveryTypeTunnel: { - LogPrint ("Garlic type tunnel"); + LogPrint (eLogDebug, "Garlic: type tunnel"); // gwHash and gwTunnel sequence is reverted uint8_t * gwHash = buf; buf += 32; @@ -521,15 +521,15 @@ namespace garlic tunnel->SendTunnelDataMsg (gwHash, gwTunnel, msg); } else - LogPrint ("No outbound tunnels available for garlic clove"); + LogPrint (eLogWarning, "Garlic: No outbound tunnels available for garlic clove"); break; } case eGarlicDeliveryTypeRouter: - LogPrint ("Garlic type router not supported"); + LogPrint (eLogWarning, "Garlic: type router not supported"); buf += 32; break; default: - LogPrint ("Unknow garlic delivery type ", (int)deliveryType); + LogPrint (eLogWarning, "Garlic: unknown delivery type ", (int)deliveryType); } buf += GetI2NPMessageLength (buf); // I2NP buf += 4; // CloveID @@ -537,7 +537,7 @@ namespace garlic buf += 3; // Certificate if (buf - buf1 > (int)len) { - LogPrint (eLogError, "Garlic clove is too long"); + LogPrint (eLogError, "Garlic: clove is too long"); break; } } @@ -601,7 +601,7 @@ namespace garlic { it->second->MessageConfirmed (msgID); m_CreatedSessions.erase (it); - LogPrint (eLogInfo, "Garlic message ", msgID, " acknowledged"); + LogPrint (eLogDebug, "Garlic: message ", msgID, " acknowledged"); } } } From e8952d7e0290a56d5ada7fed1f24e22c5ea69c0e Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 11:48:22 +0000 Subject: [PATCH 11/32] * sane log messages: TunnelPool.cpp --- TunnelPool.cpp | 34 +++++++++++++++++----------------- 1 file changed, 17 insertions(+), 17 deletions(-) diff --git a/TunnelPool.cpp b/TunnelPool.cpp index fcce1c22..3f92116d 100644 --- a/TunnelPool.cpp +++ b/TunnelPool.cpp @@ -34,12 +34,12 @@ namespace tunnel if (m_NumInboundHops > size) { m_NumInboundHops = size; - LogPrint (eLogInfo, "Inbound tunnel length has beed adjusted to ", size, " for explicit peers"); + LogPrint (eLogInfo, "Tunnels: Inbound tunnel length has beed adjusted to ", size, " for explicit peers"); } if (m_NumOutboundHops > size) { m_NumOutboundHops = size; - LogPrint (eLogInfo, "Outbound tunnel length has beed adjusted to ", size, " for explicit peers"); + LogPrint (eLogInfo, "Tunnels: Outbound tunnel length has beed adjusted to ", size, " for explicit peers"); } m_NumInboundTunnels = 1; m_NumOutboundTunnels = 1; @@ -203,7 +203,7 @@ namespace tunnel { for (auto it: m_Tests) { - LogPrint ("Tunnel test ", (int)it.first, " failed"); + LogPrint (eLogWarning, "Tunnels: test of ", (int)it.first, " failed"); // if test failed again with another tunnel we consider it failed if (it.second.first) { @@ -266,7 +266,7 @@ namespace tunnel if (m_LocalDestination) m_LocalDestination->ProcessGarlicMessage (msg); else - LogPrint (eLogWarning, "Local destination doesn't exist. Dropped"); + LogPrint (eLogWarning, "Tunnels: local destination doesn't exist, dropped"); } void TunnelPool::ProcessDeliveryStatus (std::shared_ptr msg) @@ -284,7 +284,7 @@ namespace tunnel it->second.first->SetState (eTunnelStateEstablished); if (it->second.second->GetState () == eTunnelStateTestFailed) it->second.second->SetState (eTunnelStateEstablished); - LogPrint ("Tunnel test ", it->first, " successive. ", i2p::util::GetMillisecondsSinceEpoch () - timestamp, " milliseconds"); + LogPrint (eLogDebug, "Tunnels: test of ", it->first, " successful. ", i2p::util::GetMillisecondsSinceEpoch () - timestamp, " milliseconds"); m_Tests.erase (it); } else @@ -292,7 +292,7 @@ namespace tunnel if (m_LocalDestination) m_LocalDestination->ProcessDeliveryStatusMessage (msg); else - LogPrint (eLogWarning, "Local destination doesn't exist. Dropped"); + LogPrint (eLogWarning, "Tunnels: Local destination doesn't exist, dropped"); } } @@ -328,7 +328,7 @@ namespace tunnel auto hop = SelectNextHop (prevHop); if (!hop) { - LogPrint (eLogError, "Can't select next hop"); + LogPrint (eLogError, "Tunnels: Can't select next hop for ", prevHop->GetIdentHashBase64 ()); return false; } prevHop = hop; @@ -353,7 +353,7 @@ namespace tunnel peers.push_back (r->GetRouterIdentity ()); else { - LogPrint (eLogInfo, "Can't find router for ", ident.ToBase64 ()); + LogPrint (eLogInfo, "Tunnels: Can't find router for ", ident.ToBase64 ()); i2p::data::netdb.RequestDestination (ident); return false; } @@ -366,7 +366,7 @@ namespace tunnel auto outboundTunnel = GetNextOutboundTunnel (); if (!outboundTunnel) outboundTunnel = tunnels.GetNextOutboundTunnel (); - LogPrint ("Creating destination inbound tunnel..."); + LogPrint (eLogDebug, "Tunnels: Creating destination inbound tunnel..."); std::vector > peers; if (SelectPeers (peers, true)) { @@ -375,7 +375,7 @@ namespace tunnel tunnel->SetTunnelPool (shared_from_this ()); } else - LogPrint (eLogError, "Can't create inbound tunnel. No peers available"); + LogPrint (eLogError, "Tunnels: Can't create inbound tunnel, no peers available"); } void TunnelPool::RecreateInboundTunnel (std::shared_ptr tunnel) @@ -383,7 +383,7 @@ namespace tunnel auto outboundTunnel = GetNextOutboundTunnel (); if (!outboundTunnel) outboundTunnel = tunnels.GetNextOutboundTunnel (); - LogPrint ("Re-creating destination inbound tunnel..."); + LogPrint (eLogDebug, "Tunnels: Re-creating destination inbound tunnel..."); auto newTunnel = tunnels.CreateTunnel (std::make_shared(tunnel->GetPeers ()), outboundTunnel); newTunnel->SetTunnelPool (shared_from_this()); } @@ -395,7 +395,7 @@ namespace tunnel inboundTunnel = tunnels.GetNextInboundTunnel (); if (inboundTunnel) { - LogPrint ("Creating destination outbound tunnel..."); + LogPrint (eLogDebug, "Tunnels: Creating destination outbound tunnel..."); std::vector > peers; if (SelectPeers (peers, false)) { @@ -404,10 +404,10 @@ namespace tunnel tunnel->SetTunnelPool (shared_from_this ()); } else - LogPrint (eLogError, "Can't create outbound tunnel. No peers available"); + LogPrint (eLogError, "Tunnels: Can't create outbound tunnel, no peers available"); } else - LogPrint (eLogError, "Can't create outbound tunnel. No inbound tunnels found"); + LogPrint (eLogError, "Tunnels: Can't create outbound tunnel, no inbound tunnels found"); } void TunnelPool::RecreateOutboundTunnel (std::shared_ptr tunnel) @@ -417,19 +417,19 @@ namespace tunnel inboundTunnel = tunnels.GetNextInboundTunnel (); if (inboundTunnel) { - LogPrint ("Re-creating destination outbound tunnel..."); + LogPrint (eLogDebug, "Tunnels: Re-creating destination outbound tunnel..."); auto newTunnel = tunnels.CreateTunnel ( std::make_shared (tunnel->GetPeers (), inboundTunnel->GetNextTunnelID (), inboundTunnel->GetNextIdentHash ())); newTunnel->SetTunnelPool (shared_from_this ()); } else - LogPrint ("Can't re-create outbound tunnel. No inbound tunnels found"); + LogPrint (eLogDebug, "Tunnels: Can't re-create outbound tunnel, no inbound tunnels found"); } void TunnelPool::CreatePairedInboundTunnel (std::shared_ptr outboundTunnel) { - LogPrint (eLogInfo, "Creating paired inbound tunnel..."); + LogPrint (eLogDebug, "Tunnels: Creating paired inbound tunnel..."); auto tunnel = tunnels.CreateTunnel (std::make_shared(outboundTunnel->GetInvertedPeers ()), outboundTunnel); tunnel->SetTunnelPool (shared_from_this ()); } From 1cb08fdecc3bdfe277830b40b1c6af990411d520 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 12:07:13 +0000 Subject: [PATCH 12/32] * sane log messages: util.cpp --- util.cpp | 46 ++++++++++++++++++---------------------------- 1 file changed, 18 insertions(+), 28 deletions(-) diff --git a/util.cpp b/util.cpp index 6d2ee500..722fa011 100644 --- a/util.cpp +++ b/util.cpp @@ -166,7 +166,7 @@ namespace filesystem // Create data directory if (!boost::filesystem::create_directory( path )) { - LogPrint("Failed to create data directory!"); + LogPrint(eLogError, "FS: Failed to create data directory!"); path = ""; return path; } @@ -291,13 +291,13 @@ namespace http } else { - LogPrint ("Can't connect to ", address); + LogPrint (eLogError, "HTTPClient: Can't connect to ", address); return ""; } } catch (std::exception& ex) { - LogPrint ("Failed to download ", address, " : ", ex.what ()); + LogPrint (eLogError, "HTTPClient: runtime exception: ", ex.what ()); return ""; } } @@ -334,7 +334,7 @@ namespace http } else { - LogPrint ("HTTP response ", status); + LogPrint (eLogError, "HTTPClient: error, server responds ", status); return ""; } } @@ -399,19 +399,19 @@ namespace http } else { - LogPrint("HTTP response ", status); + LogPrint (eLogError, "HTTPClient: error, server responds ", status); return status; } } else { - LogPrint("Can't connect to proxy"); + LogPrint(eLogError, "HTTPClient: Can't connect to proxy"); return 408; } } catch (std::exception& ex) { - LogPrint("Failed to download ", address, " : ", ex.what()); + LogPrint(eLogError, "HTTPClient: runtime exception: ", ex.what()); return 408; } } @@ -515,7 +515,7 @@ namespace net ifaddrs* ifaddr, *ifa = nullptr; if(getifaddrs(&ifaddr) == -1) { - LogPrint(eLogError, "Can't excute getifaddrs"); + LogPrint(eLogError, "NetIface: Can't call getifaddrs(): ", strerror(errno)); return fallback; } @@ -551,14 +551,14 @@ namespace net if(ioctl(fd, SIOCGIFMTU, &ifr) >= 0) mtu = ifr.ifr_mtu; // MTU else - LogPrint (eLogError, "Failed to run ioctl"); + LogPrint (eLogError, "NetIface: Failed to run ioctl: ", strerror(errno)); close(fd); } else - LogPrint(eLogError, "Failed to create datagram socket"); + LogPrint(eLogError, "NetIface: Failed to create datagram socket"); } else - LogPrint(eLogWarning, "Interface for local address", localAddress.to_string(), " not found"); + LogPrint(eLogWarning, "NetIface: interface for local address", localAddress.to_string(), " not found"); freeifaddrs(ifaddr); return mtu; @@ -584,9 +584,7 @@ namespace net ); if(dwRetVal != NO_ERROR) { - LogPrint( - eLogError, "GetMTU() has failed: enclosed GetAdaptersAddresses() call has failed" - ); + LogPrint(eLogError, "NetIface: GetMTU(): enclosed GetAdaptersAddresses() call has failed"); FREE(pAddresses); return fallback; } @@ -597,9 +595,7 @@ namespace net pUnicast = pCurrAddresses->FirstUnicastAddress; if(pUnicast == nullptr) { - LogPrint( - eLogError, "GetMTU() has failed: not a unicast ipv4 address, this is not supported" - ); + LogPrint(eLogError, "NetIface: GetMTU(): not a unicast ipv4 address, this is not supported"); } for(int i = 0; pUnicast != nullptr; ++i) { LPSOCKADDR lpAddr = pUnicast->Address.lpSockaddr; @@ -614,7 +610,7 @@ namespace net pCurrAddresses = pCurrAddresses->Next; } - LogPrint(eLogError, "GetMTU() error: no usable unicast ipv4 addresses found"); + LogPrint(eLogError, "NetIface: GetMTU(): no usable unicast ipv4 addresses found"); FREE(pAddresses); return fallback; } @@ -637,10 +633,7 @@ namespace net ); if(dwRetVal != NO_ERROR) { - LogPrint( - eLogError, - "GetMTU() has failed: enclosed GetAdaptersAddresses() call has failed" - ); + LogPrint(eLogError, "NetIface: GetMTU(): enclosed GetAdaptersAddresses() call has failed"); FREE(pAddresses); return fallback; } @@ -651,10 +644,7 @@ namespace net PIP_ADAPTER_UNICAST_ADDRESS firstUnicastAddress = pCurrAddresses->FirstUnicastAddress; pUnicast = pCurrAddresses->FirstUnicastAddress; if(pUnicast == nullptr) { - LogPrint( - eLogError, - "GetMTU() has failed: not a unicast ipv6 address, this is not supported" - ); + LogPrint(eLogError, "NetIface: GetMTU(): not a unicast ipv6 address, this is not supported"); } for(int i = 0; pUnicast != nullptr; ++i) { LPSOCKADDR lpAddr = pUnicast->Address.lpSockaddr; @@ -678,7 +668,7 @@ namespace net pCurrAddresses = pCurrAddresses->Next; } - LogPrint(eLogError, "GetMTU() error: no usable unicast ipv6 addresses found"); + LogPrint(eLogError, "NetIface: GetMTU(): no usable unicast ipv6 addresses found"); FREE(pAddresses); return fallback; } @@ -701,7 +691,7 @@ namespace net inet_pton(AF_INET6, localAddressUniversal.c_str(), &(inputAddress.sin6_addr)); return GetMTUWindowsIpv6(inputAddress, fallback); } else { - LogPrint(eLogError, "GetMTU() has failed: address family is not supported"); + LogPrint(eLogError, "NetIface: GetMTU(): address family is not supported"); return fallback; } From 8d998088216c228c6c4a126a16df056ea0dbcc78 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 12:12:46 +0000 Subject: [PATCH 13/32] * sane log messages: I2PTunnel.cpp --- I2PTunnel.cpp | 24 ++++++++++++------------ 1 file changed, 12 insertions(+), 12 deletions(-) diff --git a/I2PTunnel.cpp b/I2PTunnel.cpp index 09edafc5..db98c7e4 100644 --- a/I2PTunnel.cpp +++ b/I2PTunnel.cpp @@ -78,7 +78,7 @@ namespace client { if (ecode) { - LogPrint ("I2PTunnel read error: ", ecode.message ()); + LogPrint (eLogError, "I2PTunnel: read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -103,7 +103,7 @@ namespace client { if (ecode) { - LogPrint ("I2PTunnel write error: ", ecode.message ()); + LogPrint (eLogError, "I2PTunnel: write error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -124,7 +124,7 @@ namespace client { if (ecode) { - LogPrint ("I2PTunnel stream read error: ", ecode.message ()); + LogPrint (eLogError, "I2PTunnel: stream read error: ", ecode.message ()); if (ecode != boost::asio::error::operation_aborted) Terminate (); } @@ -142,12 +142,12 @@ namespace client { if (ecode) { - LogPrint ("I2PTunnel connect error: ", ecode.message ()); + LogPrint (eLogError, "I2PTunnel: connect error: ", ecode.message ()); Terminate (); } else { - LogPrint ("I2PTunnel connected"); + LogPrint (eLogDebug, "I2PTunnel: connected"); if (m_IsQuiet) StreamReceive (); else @@ -232,7 +232,7 @@ namespace client if (stream) { if (Kill()) return; - LogPrint (eLogInfo,"New I2PTunnel connection"); + LogPrint (eLogDebug, "I2PTunnel: new connection"); auto connection = std::make_shared(GetOwner(), m_Socket, stream); GetOwner()->AddHandler (connection); connection->I2PConnect (); @@ -240,7 +240,7 @@ namespace client } else { - LogPrint (eLogError,"I2P Client Tunnel Issue when creating the stream, check the previous warnings for more info."); + LogPrint (eLogError, "I2PTunnel: Client Tunnel Issue when creating the stream, check the previous warnings for more info."); Terminate(); } } @@ -282,7 +282,7 @@ namespace client if (i2p::client::context.GetAddressBook ().GetIdentHash (m_Destination, identHash)) m_DestinationIdentHash = new i2p::data::IdentHash (identHash); else - LogPrint (eLogWarning,"Remote destination ", m_Destination, " not found"); + LogPrint (eLogWarning, "I2PTunnel: Remote destination ", m_Destination, " not found"); } return m_DestinationIdentHash; } @@ -333,12 +333,12 @@ namespace client if (!ecode) { auto addr = (*it).endpoint ().address (); - LogPrint (eLogInfo, "server tunnel ", (*it).host_name (), " has been resolved to ", addr); + LogPrint (eLogInfo, "I2PTunnel: server tunnel ", (*it).host_name (), " has been resolved to ", addr); m_Endpoint.address (addr); Accept (); } else - LogPrint (eLogError, "Unable to resolve server tunnel address: ", ecode.message ()); + LogPrint (eLogError, "I2PTunnel: Unable to resolve server tunnel address: ", ecode.message ()); } void I2PServerTunnel::SetAccessList (const std::set& accessList) @@ -359,7 +359,7 @@ namespace client localDestination->AcceptStreams (std::bind (&I2PServerTunnel::HandleAccept, this, std::placeholders::_1)); } else - LogPrint ("Local destination not set for server tunnel"); + LogPrint (eLogError, "I2PTunnel: Local destination not set for server tunnel"); } void I2PServerTunnel::HandleAccept (std::shared_ptr stream) @@ -370,7 +370,7 @@ namespace client { if (!m_AccessList.count (stream->GetRemoteIdentity ()->GetIdentHash ())) { - LogPrint (eLogWarning, "Address ", stream->GetRemoteIdentity ()->GetIdentHash ().ToBase32 (), " is not in white list. Incoming connection dropped"); + LogPrint (eLogWarning, "I2PTunnel: Address ", stream->GetRemoteIdentity ()->GetIdentHash ().ToBase32 (), " is not in white list. Incoming connection dropped"); stream->Close (); return; } From 56ef0dad9c0e84e67d2e5a1fc288209102780ca7 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 12:21:37 +0000 Subject: [PATCH 14/32] * sane log messages: Daemon.cpp --- Daemon.cpp | 44 ++++++++++++++++++++++++-------------------- 1 file changed, 24 insertions(+), 20 deletions(-) diff --git a/Daemon.cpp b/Daemon.cpp index f698e90b..4991ab07 100644 --- a/Daemon.cpp +++ b/Daemon.cpp @@ -64,9 +64,8 @@ namespace i2p i2p::util::config::OptionParser(argc, argv); i2p::context.Init (); - LogPrint("\n\n\n\ni2pd starting\n"); - LogPrint("Version ", VERSION); - LogPrint("data directory: ", i2p::util::filesystem::GetDataDir().string()); + LogPrint(eLogInfo, "\n\n\n\ni2pd v", VERSION, " starting\n"); + LogPrint(eLogDebug, "data directory: ", i2p::util::filesystem::GetDataDir().string()); i2p::util::filesystem::ReadConfigFile(i2p::util::config::mapArgs, i2p::util::config::mapMultiArgs); isDaemon = i2p::util::config::GetArg("-daemon", 0); @@ -90,9 +89,9 @@ namespace i2p i2p::context.SetLowBandwidth (); } - LogPrint("CMD parameters:"); + LogPrint(eLogDebug, "Daemon: CMD parameters:"); for (int i = 0; i < argc; ++i) - LogPrint(i, " ", argv[i]); + LogPrint(eLogDebug, i, ": ", argv[i]); return true; } @@ -116,55 +115,60 @@ namespace i2p StartLog (""); // write to stdout } + LogPrint(eLogInfo, "Daemon: staring HTTP Server"); d.httpServer = std::unique_ptr(new i2p::util::HTTPServer(i2p::util::config::GetArg("-httpaddress", "127.0.0.1"), i2p::util::config::GetArg("-httpport", 7070))); d.httpServer->Start(); - LogPrint("HTTP Server started"); + + LogPrint(eLogInfo, "Daemon: starting NetDB"); i2p::data::netdb.Start(); - LogPrint("NetDB started"); + #ifdef USE_UPNP + LogPrint(eLogInfo, "Daemon: starting UPnP"); d.m_UPnP.Start (); - LogPrint(eLogInfo, "UPnP started"); #endif + LogPrint(eLogInfo, "Daemon: starting Transports"); i2p::transport::transports.Start(); - LogPrint("Transports started"); + + LogPrint(eLogInfo, "Daemon: starting Tunnels"); i2p::tunnel::tunnels.Start(); - LogPrint("Tunnels started"); + + LogPrint(eLogInfo, "Daemon: starting Client"); i2p::client::context.Start (); - LogPrint("Client started"); + // I2P Control int i2pcontrolPort = i2p::util::config::GetArg("-i2pcontrolport", 0); if (i2pcontrolPort) { + LogPrint(eLogInfo, "Daemon: starting I2PControl"); d.m_I2PControlService = std::unique_ptr(new i2p::client::I2PControlService (i2p::util::config::GetArg("-i2pcontroladdress", "127.0.0.1"), i2pcontrolPort)); d.m_I2PControlService->Start (); - LogPrint("I2PControl started"); } return true; } bool Daemon_Singleton::stop() { - LogPrint("Shutdown started."); + LogPrint(eLogInfo, "Daemon: shutting down"); + LogPrint(eLogInfo, "Daemon: stopping Client"); i2p::client::context.Stop(); - LogPrint("Client stopped"); + LogPrint(eLogInfo, "Daemon: stopping Tunnels"); i2p::tunnel::tunnels.Stop(); - LogPrint("Tunnels stopped"); #ifdef USE_UPNP + LogPrint(eLogInfo, "Daemon: stopping UPnP"); d.m_UPnP.Stop (); - LogPrint(eLogInfo, "UPnP stopped"); #endif + LogPrint(eLogInfo, "Daemon: stopping Transports"); i2p::transport::transports.Stop(); - LogPrint("Transports stopped"); + LogPrint(eLogInfo, "Daemon: stopping NetDB"); i2p::data::netdb.Stop(); - LogPrint("NetDB stopped"); + LogPrint(eLogInfo, "Daemon: stopping HTTP Server"); d.httpServer->Stop(); d.httpServer = nullptr; - LogPrint("HTTP Server stopped"); if (d.m_I2PControlService) { + LogPrint(eLogInfo, "Daemon: stopping I2PControl"); d.m_I2PControlService->Stop (); d.m_I2PControlService = nullptr; - LogPrint("I2PControl stopped"); } StopLog (); From 19c74ce9fa1dc912eaccdf0e02b835a93faa0d0a Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 12:25:48 +0000 Subject: [PATCH 15/32] * sane log messages: DaemonLinux.cpp --- DaemonLinux.cpp | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/DaemonLinux.cpp b/DaemonLinux.cpp index ac7a3402..d4b72de0 100644 --- a/DaemonLinux.cpp +++ b/DaemonLinux.cpp @@ -26,7 +26,7 @@ void handle_signal(int sig) return; } } - LogPrint("Reloading config."); + LogPrint(eLogInfo, "Daemon: Got SIGHUP, reloading config."); i2p::util::filesystem::ReadConfigFile(i2p::util::config::mapArgs, i2p::util::config::mapMultiArgs); break; case SIGABRT: @@ -59,7 +59,7 @@ namespace i2p int sid = setsid(); if (sid < 0) { - LogPrint("Error, could not create process group."); + LogPrint(eLogError, "Daemon: could not create process group."); return false; } std::string d(i2p::util::filesystem::GetDataDir().string ()); // make a copy @@ -80,12 +80,12 @@ namespace i2p pidFilehandle = open(pidfile.c_str(), O_RDWR | O_CREAT, 0600); if (pidFilehandle == -1) { - LogPrint("Error, could not create pid file (", pidfile, ")\nIs an instance already running?"); + LogPrint(eLogError, "Daemon: could not create pid file ", pidfile, ": ", strerror(errno)); return false; } if (lockf(pidFilehandle, F_TLOCK, 0) == -1) { - LogPrint("Error, could not lock pid file (", pidfile, ")\nIs an instance already running?"); + LogPrint(eLogError, "Daemon: could not lock pid file ", pidfile, ": ", strerror(errno)); return false; } char pid[10]; From 16880074fa572e7135c6ea916e5c296b0bed6869 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 12:27:47 +0000 Subject: [PATCH 16/32] * sane log messages: DaemonWin32.cpp --- DaemonWin32.cpp | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/DaemonWin32.cpp b/DaemonWin32.cpp index 96b28076..6e0c46b8 100644 --- a/DaemonWin32.cpp +++ b/DaemonWin32.cpp @@ -49,17 +49,17 @@ namespace i2p if (isDaemon == 1) { - LogPrint("Service session"); + LogPrint(eLogDebug, "Daemon: running as service"); I2PService service(SERVICE_NAME); if (!I2PService::Run(service)) { - LogPrint("Service failed to run w/err 0x%08lx\n", GetLastError()); + LogPrint(eLogError, "Daemon: Service failed to run w/err 0x%08lx\n", GetLastError()); exit(EXIT_FAILURE); } exit(EXIT_SUCCESS); } else - LogPrint("User session"); + LogPrint(eLogDebug, "Daemon: running as user"); return true; } @@ -80,4 +80,4 @@ namespace i2p } } -#endif \ No newline at end of file +#endif From 3e8c247c0582113906811e6949a7fcb952db7e79 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 12:44:03 +0000 Subject: [PATCH 17/32] * sane log messages: ClientContext.cpp --- ClientContext.cpp | 63 ++++++++++++++++++++++++++++------------------- 1 file changed, 37 insertions(+), 26 deletions(-) diff --git a/ClientContext.cpp b/ClientContext.cpp index 557deb38..6b49b53a 100644 --- a/ClientContext.cpp +++ b/ClientContext.cpp @@ -41,17 +41,18 @@ namespace client std::string proxyKeys = i2p::util::config::GetArg("-proxykeys", ""); if (proxyKeys.length () > 0) localDestination = LoadLocalDestination (proxyKeys, false); + LogPrint(eLogInfo, "Clients: starting HTTP Proxy"); m_HttpProxy = new i2p::proxy::HTTPProxy(i2p::util::config::GetArg("-httpproxyaddress", "127.0.0.1"), i2p::util::config::GetArg("-httpproxyport", 4446), localDestination); m_HttpProxy->Start(); - LogPrint("HTTP Proxy started"); + LogPrint(eLogInfo, "Clients: starting SOCKS Proxy"); m_SocksProxy = new i2p::proxy::SOCKSProxy(i2p::util::config::GetArg("-socksproxyaddress", "127.0.0.1"), i2p::util::config::GetArg("-socksproxyport", 4447), localDestination); m_SocksProxy->Start(); - LogPrint("SOCKS Proxy Started"); - // I2P tunnels + // I2P tunnels: IRC std::string ircDestination = i2p::util::config::GetArg("-ircdest", ""); if (ircDestination.length () > 0) // ircdest is presented { + LogPrint(eLogInfo, "Clients: starting IRC tunnel"); localDestination = nullptr; std::string ircKeys = i2p::util::config::GetArg("-irckeys", ""); if (ircKeys.length () > 0) @@ -60,17 +61,18 @@ namespace client auto ircTunnel = new I2PClientTunnel (ircDestination, i2p::util::config::GetArg("-ircaddress", "127.0.0.1"), ircPort, localDestination); ircTunnel->Start (); m_ClientTunnels.insert (std::make_pair(ircPort, std::unique_ptr(ircTunnel))); - LogPrint("IRC tunnel started"); } + + // I2P tunnels: local site std::string eepKeys = i2p::util::config::GetArg("-eepkeys", ""); if (eepKeys.length () > 0) // eepkeys file is presented { + LogPrint(eLogInfo, "Clients: starting server tunnel for eepsite"); localDestination = LoadLocalDestination (eepKeys, true); auto serverTunnel = new I2PServerTunnel (i2p::util::config::GetArg("-eephost", "127.0.0.1"), i2p::util::config::GetArg("-eepport", 80), localDestination); serverTunnel->Start (); m_ServerTunnels.insert (std::make_pair(localDestination->GetIdentHash (), std::unique_ptr(serverTunnel))); - LogPrint("Server tunnel started"); } ReadTunnels (); @@ -78,18 +80,18 @@ namespace client int samPort = i2p::util::config::GetArg("-samport", 0); if (samPort) { + LogPrint(eLogInfo, "Clients: starting SAM bridge"); m_SamBridge = new SAMBridge (i2p::util::config::GetArg("-samaddress", "127.0.0.1"), samPort); m_SamBridge->Start (); - LogPrint("SAM bridge started"); } // BOB int bobPort = i2p::util::config::GetArg("-bobport", 0); if (bobPort) { + LogPrint(eLogInfo, "Clients: starting BOB command channel"); m_BOBCommandChannel = new BOBCommandChannel (i2p::util::config::GetArg("-bobaddress", "127.0.0.1"), bobPort); m_BOBCommandChannel->Start (); - LogPrint("BOB command channel started"); } m_AddressBook.Start (); @@ -97,40 +99,47 @@ namespace client void ClientContext::Stop () { + LogPrint(eLogInfo, "Clients: stopping HTTP Proxy"); m_HttpProxy->Stop(); delete m_HttpProxy; m_HttpProxy = nullptr; - LogPrint("HTTP Proxy stopped"); + + LogPrint(eLogInfo, "Clients: stopping SOCKS Proxy"); m_SocksProxy->Stop(); delete m_SocksProxy; m_SocksProxy = nullptr; - LogPrint("SOCKS Proxy stopped"); + for (auto& it: m_ClientTunnels) { + LogPrint(eLogInfo, "Clients: stopping I2P client tunnel on port ", it.first); it.second->Stop (); - LogPrint("I2P client tunnel on port ", it.first, " stopped"); } m_ClientTunnels.clear (); + for (auto& it: m_ServerTunnels) { + LogPrint(eLogInfo, "Clients: stopping I2P server tunnel"); it.second->Stop (); - LogPrint("I2P server tunnel stopped"); } m_ServerTunnels.clear (); + if (m_SamBridge) { + LogPrint(eLogInfo, "Clients: stopping SAM bridge"); m_SamBridge->Stop (); delete m_SamBridge; m_SamBridge = nullptr; - LogPrint("SAM brdige stopped"); } + if (m_BOBCommandChannel) { + LogPrint(eLogInfo, "Clients: stopping BOB command channel"); m_BOBCommandChannel->Stop (); delete m_BOBCommandChannel; m_BOBCommandChannel = nullptr; - LogPrint("BOB command channel stopped"); - } + } + + LogPrint(eLogInfo, "Clients: stopping AddressBook"); m_AddressBook.Stop (); for (auto it: m_Destinations) it.second->Stop (); @@ -138,6 +147,7 @@ namespace client m_SharedLocalDestination = nullptr; } + // should be moved in i2p::utils::fs std::shared_ptr ClientContext::LoadLocalDestination (const std::string& filename, bool isPublic) { i2p::data::PrivateKeys keys; @@ -152,11 +162,11 @@ namespace client s.read ((char *)buf, len); keys.FromBuffer (buf, len); delete[] buf; - LogPrint ("Local address ", m_AddressBook.ToAddress(keys.GetPublic ()->GetIdentHash ()), " loaded"); + LogPrint (eLogInfo, "Clients: Local address ", m_AddressBook.ToAddress(keys.GetPublic ()->GetIdentHash ()), " loaded"); } else { - LogPrint ("Can't open file ", fullPath, " Creating new one"); + LogPrint (eLogError, "Clients: can't open file ", fullPath, " Creating new one"); keys = i2p::data::PrivateKeys::CreateRandomKeys (i2p::data::SIGNING_KEY_TYPE_ECDSA_SHA256_P256); std::ofstream f (fullPath, std::ofstream::binary | std::ofstream::out); size_t len = keys.GetFullLen (); @@ -165,7 +175,7 @@ namespace client f.write ((char *)buf, len); delete[] buf; - LogPrint ("New private keys file ", fullPath, " for ", m_AddressBook.ToAddress(keys.GetPublic ()->GetIdentHash ()), " created"); + LogPrint (eLogInfo, "Clients: New private keys file ", fullPath, " for ", m_AddressBook.ToAddress(keys.GetPublic ()->GetIdentHash ()), " created"); } std::shared_ptr localDestination = nullptr; @@ -173,7 +183,7 @@ namespace client auto it = m_Destinations.find (keys.GetPublic ()->GetIdentHash ()); if (it != m_Destinations.end ()) { - LogPrint (eLogWarning, "Local destination ", m_AddressBook.ToAddress(keys.GetPublic ()->GetIdentHash ()), " alreday exists"); + LogPrint (eLogWarning, "Clients: Local destination ", m_AddressBook.ToAddress(keys.GetPublic ()->GetIdentHash ()), " already exists"); localDestination = it->second; } else @@ -217,7 +227,7 @@ namespace client auto it = m_Destinations.find (keys.GetPublic ()->GetIdentHash ()); if (it != m_Destinations.end ()) { - LogPrint ("Local destination ", m_AddressBook.ToAddress(keys.GetPublic ()->GetIdentHash ()), " exists"); + LogPrint (eLogWarning, "Clients: Local destination ", m_AddressBook.ToAddress(keys.GetPublic ()->GetIdentHash ()), " exists"); if (!it->second->IsRunning ()) { it->second->Start (); @@ -240,6 +250,7 @@ namespace client return nullptr; } + // should be moved in i2p::utils::fs void ClientContext::ReadTunnels () { boost::property_tree::ptree pt; @@ -250,7 +261,7 @@ namespace client } catch (std::exception& ex) { - LogPrint (eLogWarning, "Can't read ", pathTunnelsConfigFile, ": ", ex.what ()); + LogPrint (eLogWarning, "Clients: Can't read ", pathTunnelsConfigFile, ": ", ex.what ()); return; } @@ -278,7 +289,7 @@ namespace client if (m_ClientTunnels.insert (std::make_pair (port, std::unique_ptr(clientTunnel))).second) clientTunnel->Start (); else - LogPrint (eLogError, "I2P client tunnel with port ", port, " already exists"); + LogPrint (eLogError, "Clients: I2P client tunnel with port ", port, " already exists"); numClientTunnels++; } else if (type == I2P_TUNNELS_SECTION_TYPE_SERVER || type == I2P_TUNNELS_SECTION_TYPE_HTTP) @@ -311,20 +322,20 @@ namespace client if (m_ServerTunnels.insert (std::make_pair (localDestination->GetIdentHash (), std::unique_ptr(serverTunnel))).second) serverTunnel->Start (); else - LogPrint (eLogError, "I2P server tunnel for destination ", m_AddressBook.ToAddress(localDestination->GetIdentHash ()), " already exists"); + LogPrint (eLogError, "Clients: I2P server tunnel for destination ", m_AddressBook.ToAddress(localDestination->GetIdentHash ()), " already exists"); numServerTunnels++; } else - LogPrint (eLogWarning, "Unknown section type=", type, " of ", name, " in ", pathTunnelsConfigFile); + LogPrint (eLogWarning, "Clients: Unknown section type=", type, " of ", name, " in ", pathTunnelsConfigFile); } catch (std::exception& ex) { - LogPrint (eLogError, "Can't read tunnel ", name, " params: ", ex.what ()); + LogPrint (eLogError, "Clients: Can't read tunnel ", name, " params: ", ex.what ()); } } - LogPrint (eLogInfo, numClientTunnels, " I2P client tunnels created"); - LogPrint (eLogInfo, numServerTunnels, " I2P server tunnels created"); + LogPrint (eLogInfo, "Clients: ", numClientTunnels, " I2P client tunnels created"); + LogPrint (eLogInfo, "Clients: ", numServerTunnels, " I2P server tunnels created"); } } } From 830fe7f9b84c3b2ce407613903fd2f6fa7bfc536 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 12:57:22 +0000 Subject: [PATCH 18/32] * sane log messages: Transports.cpp --- Transports.cpp | 36 ++++++++++++++++++------------------ 1 file changed, 18 insertions(+), 18 deletions(-) diff --git a/Transports.cpp b/Transports.cpp index cdd35a42..72f95fd8 100644 --- a/Transports.cpp +++ b/Transports.cpp @@ -126,12 +126,12 @@ namespace transport if (!m_SSUServer) { m_SSUServer = new SSUServer (address.port); - LogPrint ("Start listening UDP port ", address.port); + LogPrint (eLogInfo, "Transports: Start listening UDP port ", address.port); m_SSUServer->Start (); DetectExternalIP (); } else - LogPrint ("SSU server already exists"); + LogPrint (eLogError, "Transports: SSU server already exists"); } } m_PeerCleanupTimer.expires_from_now (boost::posix_time::seconds(5*SESSION_CREATION_TIMEOUT)); @@ -176,7 +176,7 @@ namespace transport } catch (std::exception& ex) { - LogPrint ("Transports: ", ex.what ()); + LogPrint (eLogError, "Transports: runtime exception: ", ex.what ()); } } } @@ -236,7 +236,7 @@ namespace transport } catch (std::exception& ex) { - LogPrint (eLogError, "Transports::PostMessages ", ex.what ()); + LogPrint (eLogError, "Transports: PostMessages exception:", ex.what ()); } if (!connected) return; } @@ -278,14 +278,14 @@ namespace transport { if (address->addressString.length () > 0) // trying to resolve { - LogPrint (eLogInfo, "Resolving NTCP ", address->addressString); + LogPrint (eLogDebug, "Transports: Resolving NTCP ", address->addressString); NTCPResolve (address->addressString, ident); return true; } } } else - LogPrint (eLogInfo, "NTCP address is not presented. Trying SSU"); + LogPrint (eLogWarning, "Transports: NTCP address is not present for ", i2p::data::GetIdentHashAbbreviation (ident), ", trying SSU"); } if (peer.numAttempts == 1)// SSU { @@ -308,21 +308,21 @@ namespace transport { if (address->addressString.length () > 0) // trying to resolve { - LogPrint (eLogInfo, "Resolving SSU ", address->addressString); + LogPrint (eLogDebug, "Transports: Resolving SSU ", address->addressString); SSUResolve (address->addressString, ident); return true; } } } } - LogPrint (eLogError, "No NTCP and SSU addresses available"); + LogPrint (eLogError, "Transports: No NTCP or SSU addresses available"); peer.Done (); m_Peers.erase (ident); return false; } else // otherwise request RI { - LogPrint ("Router not found. Requested"); + LogPrint (eLogInfo, "Transports: RouterInfo for ", ident.ToBase64 (), " not found, requested"); i2p::data::netdb.RequestDestination (ident, std::bind ( &Transports::RequestComplete, this, std::placeholders::_1, ident)); } @@ -341,13 +341,13 @@ namespace transport { if (r) { - LogPrint ("Router found. Trying to connect"); + LogPrint (eLogDebug, "Transports: RouterInfo for ", ident.ToBase64 (), " found, Trying to connect"); it->second.router = r; ConnectToPeer (ident, it->second); } else { - LogPrint ("Router not found. Failed to send messages"); + LogPrint (eLogError, "Transports: RouterInfo not found, Failed to send messages"); m_Peers.erase (it); } } @@ -371,7 +371,7 @@ namespace transport if (!ecode && peer.router) { auto address = (*it).endpoint ().address (); - LogPrint (eLogInfo, (*it).host_name (), " has been resolved to ", address); + LogPrint (eLogDebug, "Transports: ", (*it).host_name (), " has been resolved to ", address); auto addr = peer.router->GetNTCPAddress (); if (addr) { @@ -380,7 +380,7 @@ namespace transport return; } } - LogPrint (eLogError, "Unable to resolve NTCP address: ", ecode.message ()); + LogPrint (eLogError, "Transports: Unable to resolve NTCP address: ", ecode.message ()); m_Peers.erase (it1); } } @@ -403,7 +403,7 @@ namespace transport if (!ecode && peer.router) { auto address = (*it).endpoint ().address (); - LogPrint (eLogInfo, (*it).host_name (), " has been resolved to ", address); + LogPrint (eLogDebug, "Transports: ", (*it).host_name (), " has been resolved to ", address); auto addr = peer.router->GetSSUAddress (!context.SupportsV6 ());; if (addr) { @@ -411,7 +411,7 @@ namespace transport return; } } - LogPrint (eLogError, "Unable to resolve SSU address: ", ecode.message ()); + LogPrint (eLogError, "Transports: Unable to resolve SSU address: ", ecode.message ()); m_Peers.erase (it1); } } @@ -428,7 +428,7 @@ namespace transport if (ssuSession) // try SSU first { m_SSUServer->DeleteSession (ssuSession); - LogPrint ("SSU session closed"); + LogPrint (eLogDebug, "Transports: SSU session closed"); } // TODO: delete NTCP } @@ -453,7 +453,7 @@ namespace transport } } else - LogPrint (eLogError, "Can't detect external IP. SSU is not available"); + LogPrint (eLogError, "Transports: Can't detect external IP. SSU is not available"); } void Transports::PeerTest () @@ -541,7 +541,7 @@ namespace transport { if (it->second.sessions.empty () && ts > it->second.creationTime + SESSION_CREATION_TIMEOUT) { - LogPrint (eLogError, "Session to peer ", it->first.ToBase64 (), " has not been created in ", SESSION_CREATION_TIMEOUT, " seconds"); + LogPrint (eLogWarning, "Transports: Session to peer ", it->first.ToBase64 (), " has not been created in ", SESSION_CREATION_TIMEOUT, " seconds"); it = m_Peers.erase (it); } else From d9e659deb0abcec9c3a1de420b4c92b0610cc644 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 13:11:56 +0000 Subject: [PATCH 19/32] * sane log messages: Destination.cpp --- Destination.cpp | 64 ++++++++++++++++++++++++------------------------- 1 file changed, 32 insertions(+), 32 deletions(-) diff --git a/Destination.cpp b/Destination.cpp index 67042276..ec2c1741 100644 --- a/Destination.cpp +++ b/Destination.cpp @@ -34,7 +34,7 @@ namespace client if (len > 0) { inboundTunnelLen = len; - LogPrint (eLogInfo, "Inbound tunnel length set to ", len); + LogPrint (eLogInfo, "Destination: Inbound tunnel length set to ", len); } } it = params->find (I2CP_PARAM_OUTBOUND_TUNNEL_LENGTH); @@ -44,7 +44,7 @@ namespace client if (len > 0) { outboundTunnelLen = len; - LogPrint (eLogInfo, "Outbound tunnel length set to ", len); + LogPrint (eLogInfo, "Destination: Outbound tunnel length set to ", len); } } it = params->find (I2CP_PARAM_INBOUND_TUNNELS_QUANTITY); @@ -54,7 +54,7 @@ namespace client if (quantity > 0) { inboundTunnelsQuantity = quantity; - LogPrint (eLogInfo, "Inbound tunnels quantity set to ", quantity); + LogPrint (eLogInfo, "Destination: Inbound tunnels quantity set to ", quantity); } } it = params->find (I2CP_PARAM_OUTBOUND_TUNNELS_QUANTITY); @@ -64,7 +64,7 @@ namespace client if (quantity > 0) { outboundTunnelsQuantity = quantity; - LogPrint (eLogInfo, "Outbound tunnels quantity set to ", quantity); + LogPrint (eLogInfo, "Destination: Outbound tunnels quantity set to ", quantity); } } it = params->find (I2CP_PARAM_EXPLICIT_PEERS); @@ -79,14 +79,14 @@ namespace client ident.FromBase64 (b64); explicitPeers->push_back (ident); } - LogPrint (eLogInfo, "Explicit peers set to ", it->second); + LogPrint (eLogInfo, "Destination: Explicit peers set to ", it->second); } } m_Pool = i2p::tunnel::tunnels.CreateTunnelPool (inboundTunnelLen, outboundTunnelLen, inboundTunnelsQuantity, outboundTunnelsQuantity); if (explicitPeers) m_Pool->SetExplicitPeers (explicitPeers); if (m_IsPublic) - LogPrint (eLogInfo, "Local address ", GetIdentHash().ToBase32 (), " created"); + LogPrint (eLogInfo, "Destination: Local address ", GetIdentHash().ToBase32 (), " created"); } ClientDestination::~ClientDestination () @@ -112,7 +112,7 @@ namespace client } catch (std::exception& ex) { - LogPrint ("Destination: ", ex.what ()); + LogPrint (eLogError, "Destination: runtime exception: ", ex.what ()); } } } @@ -175,7 +175,7 @@ namespace client if (it->second->HasNonExpiredLeases ()) return it->second; else - LogPrint ("All leases of remote LeaseSet expired"); + LogPrint (eLogWarning, "Destination: All leases of remote LeaseSet expired"); } else { @@ -256,7 +256,7 @@ namespace client size_t offset = DATABASE_STORE_HEADER_SIZE; if (replyToken) { - LogPrint (eLogInfo, "Reply token is ignored for DatabaseStore"); + LogPrint (eLogInfo, "Destination: Reply token is ignored for DatabaseStore"); offset += 36; } std::shared_ptr leaseSet; @@ -293,7 +293,7 @@ namespace client } } else - LogPrint (eLogError, "Unexpected client's DatabaseStore type ", buf[DATABASE_STORE_TYPE_OFFSET], ". Dropped"); + LogPrint (eLogError, "Destination: Unexpected client's DatabaseStore type ", buf[DATABASE_STORE_TYPE_OFFSET], ", dropped"); auto it1 = m_LeaseSetRequests.find (buf + DATABASE_STORE_KEY_OFFSET); if (it1 != m_LeaseSetRequests.end ()) @@ -308,7 +308,7 @@ namespace client { i2p::data::IdentHash key (buf); int num = buf[32]; // num - LogPrint ("DatabaseSearchReply for ", key.ToBase64 (), " num=", num); + LogPrint (eLogDebug, "Destination: DatabaseSearchReply for ", key.ToBase64 (), " num=", num); auto it = m_LeaseSetRequests.find (key); if (it != m_LeaseSetRequests.end ()) { @@ -322,21 +322,21 @@ namespace client auto floodfill = i2p::data::netdb.FindRouter (peerHash); if (floodfill) { - LogPrint (eLogInfo, "Requesting ", key.ToBase64 (), " at ", peerHash.ToBase64 ()); + LogPrint (eLogInfo, "Destination: Requesting ", key.ToBase64 (), " at ", peerHash.ToBase64 ()); if (SendLeaseSetRequest (key, floodfill, request)) found = true; } else { - LogPrint (eLogInfo, "Found new floodfill. Request it"); + LogPrint (eLogInfo, "Destination: Found new floodfill, request it"); // TODO: recheck this message i2p::data::netdb.RequestDestination (peerHash); } } if (!found) - LogPrint (eLogError, "Suggested floodfills are not presented in netDb"); + LogPrint (eLogError, "Destination: Suggested floodfills are not presented in netDb"); } else - LogPrint (eLogInfo, key.ToBase64 (), " was not found on ", MAX_NUM_FLOODFILLS_PER_REQUEST," floodfills"); + LogPrint (eLogInfo, "Destination: ", key.ToBase64 (), " was not found on ", MAX_NUM_FLOODFILLS_PER_REQUEST, " floodfills"); if (!found) { if (request->requestComplete) request->requestComplete (nullptr); @@ -344,7 +344,7 @@ namespace client } } else - LogPrint ("Request for ", key.ToBase64 (), " not found"); + LogPrint (eLogWarning, "Destination: Request for ", key.ToBase64 (), " not found"); } void ClientDestination::HandleDeliveryStatusMessage (std::shared_ptr msg) @@ -352,7 +352,7 @@ namespace client uint32_t msgID = bufbe32toh (msg->GetPayload () + DELIVERY_STATUS_MSGID_OFFSET); if (msgID == m_PublishReplyToken) { - LogPrint (eLogDebug, "Publishing confirmed"); + LogPrint (eLogDebug, "Destination: Publishing LeaseSet confirmed"); m_ExcludedFloodfills.clear (); m_PublishReplyToken = 0; } @@ -372,30 +372,30 @@ namespace client { if (!m_LeaseSet || !m_Pool) { - LogPrint (eLogError, "Can't publish non-existing LeaseSet"); + LogPrint (eLogError, "Destination: Can't publish non-existing LeaseSet"); return; } if (m_PublishReplyToken) { - LogPrint (eLogInfo, "Publishing is pending"); + LogPrint (eLogDebug, "Destination: Publishing LeaseSet is pending"); return; } auto outbound = m_Pool->GetNextOutboundTunnel (); if (!outbound) { - LogPrint ("Can't publish LeaseSet. No outbound tunnels"); + LogPrint (eLogError, "Destination: Can't publish LeaseSet. No outbound tunnels"); return; } std::set excluded; auto floodfill = i2p::data::netdb.GetClosestFloodfill (m_LeaseSet->GetIdentHash (), m_ExcludedFloodfills); if (!floodfill) { - LogPrint ("Can't publish LeaseSet. No more floodfills found"); + LogPrint (eLogError, "Destination: Can't publish LeaseSet, no more floodfills found"); m_ExcludedFloodfills.clear (); return; } m_ExcludedFloodfills.insert (floodfill->GetIdentHash ()); - LogPrint (eLogDebug, "Publish LeaseSet of ", GetIdentHash ().ToBase32 ()); + LogPrint (eLogDebug, "Destination: Publish LeaseSet of ", GetIdentHash ().ToBase32 ()); RAND_bytes ((uint8_t *)&m_PublishReplyToken, 4); auto msg = WrapMessage (floodfill, i2p::CreateDatabaseStoreMsg (m_LeaseSet, m_PublishReplyToken)); m_PublishConfirmationTimer.expires_from_now (boost::posix_time::seconds(PUBLISH_CONFIRMATION_TIMEOUT)); @@ -410,7 +410,7 @@ namespace client { if (m_PublishReplyToken) { - LogPrint (eLogWarning, "Publish confirmation was not received in ", PUBLISH_CONFIRMATION_TIMEOUT, "seconds. Try again"); + LogPrint (eLogWarning, "Destination: Publish confirmation was not received in ", PUBLISH_CONFIRMATION_TIMEOUT, " seconds, will try again"); m_PublishReplyToken = 0; Publish (); } @@ -433,7 +433,7 @@ namespace client if (dest) dest->HandleDataMessagePayload (buf, length); else - LogPrint ("Missing streaming destination"); + LogPrint (eLogError, "Destination: Missing streaming destination"); } break; case PROTOCOL_TYPE_DATAGRAM: @@ -441,10 +441,10 @@ namespace client if (m_DatagramDestination) m_DatagramDestination->HandleDataMessagePayload (fromPort, toPort, buf, length); else - LogPrint ("Missing streaming destination"); + LogPrint (eLogError, "Destination: Missing datagram destination"); break; default: - LogPrint ("Data: unexpected protocol ", buf[9]); + LogPrint (eLogError, "Destination: Data: unexpected protocol ", buf[9]); } } @@ -564,23 +564,23 @@ namespace client } else // duplicate { - LogPrint (eLogError, "Request of ", dest.ToBase64 (), " is pending already"); + LogPrint (eLogWarning, "Destination: Request of LeaseSet ", dest.ToBase64 (), " is pending already"); // TODO: queue up requests if (request->requestComplete) request->requestComplete (nullptr); } } else - LogPrint (eLogError, "No floodfills found"); + LogPrint (eLogError, "Destination: Can't request LeaseSet, no floodfills found"); } bool ClientDestination::SendLeaseSetRequest (const i2p::data::IdentHash& dest, std::shared_ptr nextFloodfill, std::shared_ptr request) { auto replyTunnel = m_Pool->GetNextInboundTunnel (); - if (!replyTunnel) LogPrint (eLogError, "No inbound tunnels found"); + if (!replyTunnel) LogPrint (eLogError, "Destination: Can't send LeaseSet request, no inbound tunnels found"); auto outboundTunnel = m_Pool->GetNextOutboundTunnel (); - if (!outboundTunnel) LogPrint (eLogError, "No outbound tunnels found"); + if (!outboundTunnel) LogPrint (eLogError, "Destination: Can't send LeaseSet request, no outbound tunnels found"); if (replyTunnel && outboundTunnel) { @@ -632,7 +632,7 @@ namespace client } else { - LogPrint (eLogInfo, dest.ToBase64 (), " was not found within ", MAX_LEASESET_REQUEST_TIMEOUT, " seconds"); + LogPrint (eLogWarning, "Destination: ", dest.ToBase64 (), " was not found within ", MAX_LEASESET_REQUEST_TIMEOUT, " seconds"); done = true; } @@ -663,7 +663,7 @@ namespace client { if (!it->second->HasNonExpiredLeases ()) // all leases expired { - LogPrint ("Remote LeaseSet ", it->second->GetIdentHash ().ToBase64 (), " expired"); + LogPrint (eLogWarning, "Destination: Remote LeaseSet ", it->second->GetIdentHash ().ToBase64 (), " expired"); it = m_RemoteLeaseSets.erase (it); } else From 642d0e6f74b42bee042ea4121493dc333a791ae6 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 13:33:58 +0000 Subject: [PATCH 20/32] * sane log messages: Streaming.cpp --- Streaming.cpp | 66 ++++++++++++++++++++++----------------------------- 1 file changed, 29 insertions(+), 37 deletions(-) diff --git a/Streaming.cpp b/Streaming.cpp index 99223512..3af8b184 100644 --- a/Streaming.cpp +++ b/Streaming.cpp @@ -53,7 +53,7 @@ namespace stream delete it; m_SavedPackets.clear (); - LogPrint (eLogDebug, "Stream deleted"); + LogPrint (eLogDebug, "Streaming: Stream deleted"); } void Stream::Terminate () @@ -83,12 +83,12 @@ namespace stream if (!receivedSeqn && !isSyn) { // plain ack - LogPrint (eLogDebug, "Plain ACK received"); + LogPrint (eLogDebug, "Streaming: Plain ACK received"); delete packet; return; } - LogPrint (eLogDebug, "Received seqn=", receivedSeqn); + LogPrint (eLogDebug, "Streaming: Received seqn=", receivedSeqn); if (isSyn || receivedSeqn == m_LastReceivedSequenceNumber + 1) { // we have received next in sequence message @@ -128,13 +128,13 @@ namespace stream if (receivedSeqn <= m_LastReceivedSequenceNumber) { // we have received duplicate - LogPrint (eLogWarning, "Duplicate message ", receivedSeqn, " received"); + LogPrint (eLogWarning, "Streaming: Duplicate message ", receivedSeqn, " received"); SendQuickAck (); // resend ack for previous message again delete packet; // packet dropped } else { - LogPrint (eLogWarning, "Missing messages from ", m_LastReceivedSequenceNumber + 1, " to ", receivedSeqn - 1); + LogPrint (eLogWarning, "Streaming: Missing messages from ", m_LastReceivedSequenceNumber + 1, " to ", receivedSeqn - 1); // save message and wait for missing message again SavePacket (packet); if (m_LastReceivedSequenceNumber >= 0) @@ -169,44 +169,37 @@ namespace stream // process flags uint32_t receivedSeqn = packet->GetSeqn (); uint16_t flags = packet->GetFlags (); - LogPrint (eLogDebug, "Process seqn=", receivedSeqn, ", flags=", flags); + LogPrint (eLogDebug, "Streaming: Process seqn=", receivedSeqn, ", flags=", flags); const uint8_t * optionData = packet->GetOptionData (); - if (flags & PACKET_FLAG_SYNCHRONIZE) - LogPrint (eLogDebug, "Synchronize"); if (flags & PACKET_FLAG_DELAY_REQUESTED) - { optionData += 2; - } if (flags & PACKET_FLAG_FROM_INCLUDED) { m_RemoteIdentity = std::make_shared(optionData, packet->GetOptionSize ()); optionData += m_RemoteIdentity->GetFullLen (); - LogPrint (eLogInfo, "From identity ", m_RemoteIdentity->GetIdentHash ().ToBase64 ()); if (!m_RemoteLeaseSet) - LogPrint (eLogDebug, "Incoming stream from ", m_RemoteIdentity->GetIdentHash ().ToBase64 ()); + LogPrint (eLogDebug, "Streaming: Incoming stream from ", m_RemoteIdentity->GetIdentHash ().ToBase64 ()); } if (flags & PACKET_FLAG_MAX_PACKET_SIZE_INCLUDED) { uint16_t maxPacketSize = bufbe16toh (optionData); - LogPrint (eLogDebug, "Max packet size ", maxPacketSize); optionData += 2; } if (flags & PACKET_FLAG_SIGNATURE_INCLUDED) { - LogPrint (eLogDebug, "Signature"); uint8_t signature[256]; auto signatureLen = m_RemoteIdentity->GetSignatureLen (); memcpy (signature, optionData, signatureLen); memset (const_cast(optionData), 0, signatureLen); if (!m_RemoteIdentity->Verify (packet->GetBuffer (), packet->GetLength (), signature)) { - LogPrint (eLogError, "Signature verification failed"); - Close (); + LogPrint (eLogError, "Streaming: Signature verification failed"); + Close (); flags |= PACKET_FLAG_CLOSE; } memcpy (const_cast(optionData), signature, signatureLen); @@ -226,7 +219,6 @@ namespace stream if (flags & (PACKET_FLAG_CLOSE | PACKET_FLAG_RESET)) { - LogPrint (eLogInfo, (flags & PACKET_FLAG_RESET) ? "Reset" : "Closed"); m_Status = eStreamStatusReset; Close (); } @@ -254,7 +246,7 @@ namespace stream } if (nacked) { - LogPrint (eLogDebug, "Packet ", seqn, " NACK"); + LogPrint (eLogDebug, "Streaming: Packet ", seqn, " NACK"); it++; continue; } @@ -418,7 +410,7 @@ namespace stream } if (lastReceivedSeqn < 0) { - LogPrint (eLogError, "No packets have been received yet"); + LogPrint (eLogError, "Streaming: No packets have been received yet"); return; } @@ -474,7 +466,7 @@ namespace stream p.len = size; SendPackets (std::vector { &p }); - LogPrint ("Quick Ack sent. ", (int)numNacks, " NACKs"); + LogPrint (eLogDebug, "Streaming: Quick Ack sent. ", (int)numNacks, " NACKs"); } void Stream::Close () @@ -485,7 +477,7 @@ namespace stream m_Status = eStreamStatusClosing; Close (); // recursion if (m_Status == eStreamStatusClosing) //still closing - LogPrint (eLogInfo, "Trying to send stream data before closing"); + LogPrint (eLogInfo, "Streaming: Trying to send stream data before closing"); break; case eStreamStatusReset: SendClose (); @@ -507,7 +499,7 @@ namespace stream m_LocalDestination.DeleteStream (shared_from_this ()); break; default: - LogPrint (eLogWarning, "Unexpected stream status ", (int)m_Status); + LogPrint (eLogWarning, "Streaming: Unexpected stream status ", (int)m_Status); }; } @@ -539,7 +531,7 @@ namespace stream p->len = size; m_Service.post (std::bind (&Stream::SendPacket, shared_from_this (), p)); - LogPrint ("FIN sent"); + LogPrint (eLogDebug, "Streaming: FIN sent"); } size_t Stream::ConcatenatePackets (uint8_t * buf, size_t len) @@ -593,7 +585,7 @@ namespace stream UpdateCurrentRemoteLease (); if (!m_RemoteLeaseSet) { - LogPrint (eLogError, "Can't send packets. Missing remote LeaseSet"); + LogPrint (eLogError, "Streaming: Can't send packets, missing remote LeaseSet"); return; } } @@ -601,7 +593,7 @@ namespace stream m_CurrentOutboundTunnel = m_LocalDestination.GetOwner ()->GetTunnelPool ()->GetNewOutboundTunnel (m_CurrentOutboundTunnel); if (!m_CurrentOutboundTunnel) { - LogPrint (eLogError, "No outbound tunnels in the pool"); + LogPrint (eLogError, "Streaming: No outbound tunnels in the pool"); return; } @@ -625,7 +617,7 @@ namespace stream m_CurrentOutboundTunnel->SendTunnelDataMsg (msgs); } else - LogPrint (eLogWarning, "All leases are expired"); + LogPrint (eLogWarning, "Streaming: All leases are expired"); } @@ -644,7 +636,7 @@ namespace stream // check for resend attempts if (m_NumResendAttempts >= MAX_NUM_RESEND_ATTEMPTS) { - LogPrint (eLogWarning, "Stream packet was not ACKed after ", MAX_NUM_RESEND_ATTEMPTS, " attempts. Terminate"); + LogPrint (eLogWarning, "Streaming: packet was not ACKed after ", MAX_NUM_RESEND_ATTEMPTS, " attempts, terminate"); m_Status = eStreamStatusReset; Close (); return; @@ -678,12 +670,12 @@ namespace stream // no break here case 4: UpdateCurrentRemoteLease (); // pick another lease - LogPrint (eLogWarning, "Another remote lease has been selected for stream"); + LogPrint (eLogWarning, "Streaming: Another remote lease has been selected for stream"); break; case 3: // pick another outbound tunnel m_CurrentOutboundTunnel = m_LocalDestination.GetOwner ()->GetTunnelPool ()->GetNextOutboundTunnel (m_CurrentOutboundTunnel); - LogPrint (eLogWarning, "Another outbound tunnel has been selected for stream"); + LogPrint (eLogWarning, "Streaming: Another outbound tunnel has been selected for stream"); break; default: ; } @@ -699,7 +691,7 @@ namespace stream { if (m_LastReceivedSequenceNumber < 0) { - LogPrint (eLogWarning, "SYN has not been recived after ", ACK_SEND_TIMEOUT, " milliseconds after follow on. Terminate"); + LogPrint (eLogWarning, "Streaming: SYN has not been recived after ", ACK_SEND_TIMEOUT, " milliseconds after follow on, terminate"); m_Status = eStreamStatusReset; Close (); return; @@ -716,7 +708,7 @@ namespace stream { m_RemoteLeaseSet = m_LocalDestination.GetOwner ()->FindLeaseSet (m_RemoteIdentity->GetIdentHash ()); if (!m_RemoteLeaseSet) - LogPrint ("LeaseSet ", m_RemoteIdentity->GetIdentHash ().ToBase64 (), " not found"); + LogPrint (eLogError, "Streaming: LeaseSet ", m_RemoteIdentity->GetIdentHash ().ToBase64 (), " not found"); } if (m_RemoteLeaseSet) { @@ -819,7 +811,7 @@ namespace stream it->second->HandleNextPacket (packet); else { - LogPrint ("Unknown stream sendStreamID=", sendStreamID); + LogPrint (eLogError, "Streaming: Unknown stream sendStreamID=", sendStreamID); delete packet; } } @@ -833,7 +825,7 @@ namespace stream m_Acceptor (incomingStream); else { - LogPrint (eLogInfo, "Acceptor for incoming stream is not set"); + LogPrint (eLogWarning, "Streaming: Acceptor for incoming stream is not set"); if (m_PendingIncomingStreams.size () < MAX_PENDING_INCOMING_BACKLOG) { m_PendingIncomingStreams.push_back (incomingStream); @@ -841,11 +833,11 @@ namespace stream m_PendingIncomingTimer.expires_from_now (boost::posix_time::seconds(PENDING_INCOMING_TIMEOUT)); m_PendingIncomingTimer.async_wait (std::bind (&StreamingDestination::HandlePendingIncomingTimer, this, std::placeholders::_1)); - LogPrint (eLogInfo, "Pending incoming stream added"); + LogPrint (eLogDebug, "Streaming: Pending incoming stream added"); } else { - LogPrint (eLogError, "Pending incoming streams backlog exceeds ", MAX_PENDING_INCOMING_BACKLOG); + LogPrint (eLogWarning, "Streaming: Pending incoming streams backlog exceeds ", MAX_PENDING_INCOMING_BACKLOG); incomingStream->Close (); } } @@ -861,7 +853,7 @@ namespace stream return; } // TODO: should queue it up - LogPrint ("Unknown stream receiveStreamID=", receiveStreamID); + LogPrint (eLogError, "Streaming: Unknown stream receiveStreamID=", receiveStreamID); delete packet; } } @@ -917,7 +909,7 @@ namespace stream { if (ecode != boost::asio::error::operation_aborted) { - LogPrint (eLogInfo, "Pending incoming timeout expired"); + LogPrint (eLogWarning, "Streaming: Pending incoming timeout expired"); for (auto it: m_PendingIncomingStreams) it->Close (); m_PendingIncomingStreams.clear (); From 01a502339c56792df2d2547f2d6900737045b20d Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 13:37:31 +0000 Subject: [PATCH 21/32] * sane log messages: api.cpp --- api.cpp | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/api.cpp b/api.cpp index eb64309a..5858dc6d 100644 --- a/api.cpp +++ b/api.cpp @@ -27,23 +27,23 @@ namespace api StartLog (logStream); else StartLog (i2p::util::filesystem::GetFullPath (i2p::util::filesystem::GetAppName () + ".log")); + LogPrint(eLogInfo, "API: starting NetDB"); i2p::data::netdb.Start(); - LogPrint("NetDB started"); + LogPrint(eLogInfo, "API: starting Transports"); i2p::transport::transports.Start(); - LogPrint("Transports started"); + LogPrint(eLogInfo, "API: starting Tunnels"); i2p::tunnel::tunnels.Start(); - LogPrint("Tunnels started"); } void StopI2P () { - LogPrint("Shutdown started."); + LogPrint(eLogInfo, "API: shutting down"); + LogPrint(eLogInfo, "API: stopping Tunnels"); i2p::tunnel::tunnels.Stop(); - LogPrint("Tunnels stopped"); + LogPrint(eLogInfo, "API: stopping Transports"); i2p::transport::transports.Stop(); - LogPrint("Transports stopped"); + LogPrint(eLogInfo, "API: stopping NetDB"); i2p::data::netdb.Stop(); - LogPrint("NetDB stopped"); StopLog (); } From ce4ed190292a94585561f7b4f175c226344df78a Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 13:46:56 +0000 Subject: [PATCH 22/32] * sane log messages: SSU.cpp --- SSU.cpp | 28 ++++++++++++++-------------- 1 file changed, 14 insertions(+), 14 deletions(-) diff --git a/SSU.cpp b/SSU.cpp index 64045ae4..699f3e94 100644 --- a/SSU.cpp +++ b/SSU.cpp @@ -86,7 +86,7 @@ namespace transport } catch (std::exception& ex) { - LogPrint (eLogError, "SSU server: ", ex.what ()); + LogPrint (eLogError, "SSU: server runtime exception: ", ex.what ()); } } } @@ -101,7 +101,7 @@ namespace transport } catch (std::exception& ex) { - LogPrint (eLogError, "SSU V6 server: ", ex.what ()); + LogPrint (eLogError, "SSU: v6 server runtime exception: ", ex.what ()); } } } @@ -116,7 +116,7 @@ namespace transport } catch (std::exception& ex) { - LogPrint (eLogError, "SSU receivers: ", ex.what ()); + LogPrint (eLogError, "SSU: receivers runtime exception: ", ex.what ()); } } } @@ -179,7 +179,7 @@ namespace transport } else { - LogPrint ("SSU receive error: ", ecode.message ()); + LogPrint (eLogError, "SSU: receive error: ", ecode.message ()); delete packet; } } @@ -206,7 +206,7 @@ namespace transport } else { - LogPrint ("SSU V6 receive error: ", ecode.message ()); + LogPrint (eLogError, "SSU: v6 receive error: ", ecode.message ()); delete packet; } } @@ -277,7 +277,7 @@ namespace transport if (address) CreateSession (router, address->host, address->port, peerTest); else - LogPrint (eLogWarning, "Router ", i2p::data::GetIdentHashAbbreviation (router->GetIdentHash ()), " doesn't have SSU address"); + LogPrint (eLogWarning, "SSU: Router ", i2p::data::GetIdentHashAbbreviation (router->GetIdentHash ()), " doesn't have SSU address"); } void SSUServer::CreateSession (std::shared_ptr router, @@ -312,7 +312,7 @@ namespace transport auto session = std::make_shared (*this, remoteEndpoint, router, peerTest); sessions[remoteEndpoint] = session; // connect - LogPrint ("Creating new SSU session to [", i2p::data::GetIdentHashAbbreviation (router->GetIdentHash ()), "] ", + LogPrint (eLogInfo, "SSU: Creating new session to [", i2p::data::GetIdentHashAbbreviation (router->GetIdentHash ()), "] ", remoteEndpoint.address ().to_string (), ":", remoteEndpoint.port ()); session->Connect (); } @@ -359,15 +359,15 @@ namespace transport } if (!introducer) { - LogPrint (eLogWarning, "Can't connect to unreachable router. No ipv4 introducers presented"); + LogPrint (eLogWarning, "SSU: Can't connect to unreachable router and no ipv4 introducers present"); return; } if (introducerSession) // session found - LogPrint (eLogInfo, "Session to introducer already exists"); + LogPrint (eLogInfo, "SSU: Session to introducer already exists"); else // create new { - LogPrint (eLogInfo, "Creating new session to introducer"); + LogPrint (eLogInfo, "SSU: Creating new session to introducer"); boost::asio::ip::udp::endpoint introducerEndpoint (introducer->iHost, introducer->iPort); introducerSession = std::make_shared (*this, introducerEndpoint, router); m_Sessions[introducerEndpoint] = introducerSession; @@ -376,7 +376,7 @@ namespace transport auto session = std::make_shared (*this, remoteEndpoint, router, peerTest); m_Sessions[remoteEndpoint] = session; // introduce - LogPrint ("Introduce new SSU session to [", i2p::data::GetIdentHashAbbreviation (router->GetIdentHash ()), + LogPrint (eLogInfo, "SSU: Introduce new session to [", i2p::data::GetIdentHashAbbreviation (router->GetIdentHash ()), "] through introducer ", introducer->iHost, ":", introducer->iPort); session->WaitForIntroduction (); if (i2p::context.GetRouterInfo ().UsesIntroducer ()) // if we are unreachable @@ -387,10 +387,10 @@ namespace transport introducerSession->Introduce (*introducer, router); } else - LogPrint (eLogWarning, "Can't connect to unreachable router. No introducers presented"); + LogPrint (eLogWarning, "SSU: Can't connect to unreachable router and no introducers present"); } else - LogPrint (eLogWarning, "Router ", i2p::data::GetIdentHashAbbreviation (router->GetIdentHash ()), " doesn't have SSU address"); + LogPrint (eLogWarning, "SSU: Router ", i2p::data::GetIdentHashAbbreviation (router->GetIdentHash ()), " doesn't have SSU address"); } } @@ -595,7 +595,7 @@ namespace transport it++; } if (numDeleted > 0) - LogPrint (eLogInfo, numDeleted, " peer tests have been expired"); + LogPrint (eLogDebug, "SSU: ", numDeleted, " peer tests have been expired"); SchedulePeerTestsCleanupTimer (); } } From 3b5d9d6cee3b00d02124e7babd3716fe1ec62ed3 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 13:49:57 +0000 Subject: [PATCH 23/32] * sane log messages: RouterContext.cpp --- RouterContext.cpp | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/RouterContext.cpp b/RouterContext.cpp index 6629f774..4cdb9e63 100644 --- a/RouterContext.cpp +++ b/RouterContext.cpp @@ -255,8 +255,11 @@ namespace i2p auto mtu = i2p::util::net::GetMTU (host); if (mtu) { - LogPrint ("Our v6 MTU=", mtu); - if (mtu > 1472) mtu = 1472; + LogPrint (eLogDebug, "Router: Our v6 MTU=", mtu); + if (mtu > 1472) { // TODO: magic constant + mtu = 1472; + LogPrint(eLogWarning, "Router: MTU dropped to upper limit of 1472 bytes"); + } } m_RouterInfo.AddSSUAddress (host.to_string ().c_str (), port, GetIdentHash (), mtu ? mtu : 1472); // TODO updated = true; From 89e3178ea3dcc0cbce67c5b31c6eae82cbd312a7 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 13:53:28 +0000 Subject: [PATCH 24/32] * sane log messages: HTTPServer.cpp --- HTTPServer.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/HTTPServer.cpp b/HTTPServer.cpp index f4cd7b82..82589765 100644 --- a/HTTPServer.cpp +++ b/HTTPServer.cpp @@ -597,7 +597,7 @@ namespace util { end = str.find ('&', pos); std::string param = str.substr (pos, end - pos); - LogPrint (param); + LogPrint (eLogDebug, "HTTPServer: extracted parameters: ", param); size_t e = param.find ('='); if (e != std::string::npos) params[param.substr(0, e)] = param.substr(e+1); @@ -968,7 +968,7 @@ namespace util void HTTPConnection::HandleDestinationRequest (const std::string& address, const std::string& uri) { std::string request = "GET " + uri + " HTTP/1.1\r\nHost:" + address + "\r\n\r\n"; - LogPrint("HTTP Client Request: ", request); + LogPrint(eLogDebug, "HTTPServer: client request: ", request); SendToAddress (address, 80, request.c_str (), request.size ()); } @@ -977,7 +977,7 @@ namespace util i2p::data::IdentHash destination; if (!i2p::client::context.GetAddressBook ().GetIdentHash (address, destination)) { - LogPrint ("Unknown address ", address); + LogPrint (eLogWarning, "HTTPServer: Unknown address ", address); SendReply ("" + itoopieImage + "
Unknown address " + address + "", 404); return; } From 1cb0826de06cf030b7b61adb476b1a5577298c06 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 14:06:18 +0000 Subject: [PATCH 25/32] * sane log messages: SSUData.cpp --- SSUData.cpp | 38 +++++++++++++++++++------------------- 1 file changed, 19 insertions(+), 19 deletions(-) diff --git a/SSUData.cpp b/SSUData.cpp index 1106cf89..33c85d71 100644 --- a/SSUData.cpp +++ b/SSUData.cpp @@ -14,7 +14,7 @@ namespace transport { if (msg->len + fragmentSize > msg->maxLen) { - LogPrint (eLogInfo, "SSU I2NP message size ", msg->maxLen, " is not enough"); + LogPrint (eLogWarning, "SSU: I2NP message size ", msg->maxLen, " is not enough"); auto newMsg = NewI2NPMessage (); *newMsg = *msg; msg = newMsg; @@ -64,11 +64,11 @@ namespace transport m_PacketSize >>= 4; m_PacketSize <<= 4; if (m_PacketSize > m_MaxPacketSize) m_PacketSize = m_MaxPacketSize; - LogPrint ("MTU=", ssuAddress->mtu, " packet size=", m_PacketSize); + LogPrint (eLogDebug, "SSU: MTU=", ssuAddress->mtu, " packet size=", m_PacketSize); } else { - LogPrint (eLogWarning, "Unexpected MTU ", ssuAddress->mtu); + LogPrint (eLogWarning, "SSU: Unexpected MTU ", ssuAddress->mtu); m_PacketSize = m_MaxPacketSize; } } @@ -162,7 +162,7 @@ namespace transport uint8_t fragmentNum = fragmentInfo >> 17; // bits 23 - 17 if (fragmentSize >= SSU_V4_MAX_PACKET_SIZE) { - LogPrint (eLogError, "Fragment size ", fragmentSize, "exceeds max SSU packet size"); + LogPrint (eLogError, "SSU: Fragment size ", fragmentSize, " exceeds max SSU packet size"); return; } @@ -199,23 +199,23 @@ namespace transport break; } if (isLast) - LogPrint (eLogDebug, "Message ", msgID, " complete"); + LogPrint (eLogDebug, "SSU: Message ", msgID, " complete"); } } else { if (fragmentNum < incompleteMessage->nextFragmentNum) // duplicate fragment - LogPrint (eLogWarning, "Duplicate fragment ", (int)fragmentNum, " of message ", msgID, ". Ignored"); + LogPrint (eLogWarning, "SSU: Duplicate fragment ", (int)fragmentNum, " of message ", msgID, ", ignored"); else { // missing fragment - LogPrint (eLogWarning, "Missing fragments from ", (int)incompleteMessage->nextFragmentNum, " to ", fragmentNum - 1, " of message ", msgID); + LogPrint (eLogWarning, "SSU: Missing fragments from ", (int)incompleteMessage->nextFragmentNum, " to ", fragmentNum - 1, " of message ", msgID); auto savedFragment = new Fragment (fragmentNum, buf, fragmentSize, isLast); if (incompleteMessage->savedFragments.insert (std::unique_ptr(savedFragment)).second) incompleteMessage->lastFragmentInsertTime = i2p::util::GetSecondsSinceEpoch (); else - LogPrint (eLogWarning, "Fragment ", (int)fragmentNum, " of message ", msgID, " already saved"); + LogPrint (eLogWarning, "SSU: Fragment ", (int)fragmentNum, " of message ", msgID, " already saved"); } isLast = false; } @@ -241,18 +241,18 @@ namespace transport m_Handler.PutNextMessage (msg); } else - LogPrint (eLogWarning, "SSU message ", msgID, " already received"); + LogPrint (eLogWarning, "SSU: Message ", msgID, " already received"); } else { // we expect DeliveryStatus if (msg->GetTypeID () == eI2NPDeliveryStatus) { - LogPrint ("SSU session established"); + LogPrint (eLogDebug, "SSU: session established"); m_Session.Established (); } else - LogPrint (eLogError, "SSU unexpected message ", (int)msg->GetTypeID ()); + LogPrint (eLogError, "SSU: unexpected message ", (int)msg->GetTypeID ()); } } else @@ -271,7 +271,7 @@ namespace transport //uint8_t * start = buf; uint8_t flag = *buf; buf++; - LogPrint (eLogDebug, "Process SSU data flags=", (int)flag, " len=", len); + LogPrint (eLogDebug, "SSU: Process data, flags=", (int)flag, ", len=", len); // process acks if presented if (flag & (DATA_FLAG_ACK_BITFIELDS_INCLUDED | DATA_FLAG_EXPLICIT_ACKS_INCLUDED)) ProcessAcks (buf, flag); @@ -280,7 +280,7 @@ namespace transport { uint8_t extendedDataSize = *buf; buf++; // size - LogPrint (eLogDebug, "SSU extended data of ", extendedDataSize, " bytes presented"); + LogPrint (eLogDebug, "SSU: extended data of ", extendedDataSize, " bytes present"); buf += extendedDataSize; } // process data @@ -292,7 +292,7 @@ namespace transport uint32_t msgID = msg->ToSSU (); if (m_SentMessages.count (msgID) > 0) { - LogPrint (eLogWarning, "SSU message ", msgID, " already sent"); + LogPrint (eLogWarning, "SSU: message ", msgID, " already sent"); return; } if (m_SentMessages.empty ()) // schedule resend at first message only @@ -349,7 +349,7 @@ namespace transport } catch (boost::system::system_error& ec) { - LogPrint (eLogError, "Can't send SSU fragment ", ec.what ()); + LogPrint (eLogError, "SSU: Can't send data fragment ", ec.what ()); } if (!isLast) { @@ -383,7 +383,7 @@ namespace transport { if (fragmentNum > 64) { - LogPrint (eLogWarning, "Fragment number ", fragmentNum, " exceeds 64"); + LogPrint (eLogWarning, "SSU: Fragment number ", fragmentNum, " exceeds 64"); return; } uint8_t buf[64 + 18]; @@ -437,7 +437,7 @@ namespace transport } catch (boost::system::system_error& ec) { - LogPrint (eLogError, "Can't resend SSU fragment ", ec.what ()); + LogPrint (eLogError, "SSU: Can't resend data fragment ", ec.what ()); } } @@ -447,7 +447,7 @@ namespace transport } else { - LogPrint (eLogError, "SSU message has not been ACKed after ", MAX_NUM_RESENDS, " attempts. Deleted"); + LogPrint (eLogError, "SSU: message has not been ACKed after ", MAX_NUM_RESENDS, " attempts, deleted"); it = m_SentMessages.erase (it); } } @@ -491,7 +491,7 @@ namespace transport { if (ts > it->second->lastFragmentInsertTime + INCOMPLETE_MESSAGES_CLEANUP_TIMEOUT) { - LogPrint (eLogError, "SSU message ", it->first, " was not completed in ", INCOMPLETE_MESSAGES_CLEANUP_TIMEOUT, " seconds. Deleted"); + LogPrint (eLogWarning, "SSU: message ", it->first, " was not completed in ", INCOMPLETE_MESSAGES_CLEANUP_TIMEOUT, " seconds, deleted"); it = m_IncompleteMessages.erase (it); } else From 5266d4d79c30bdc9eca221c5ab02c26379860ded Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 14:07:50 +0000 Subject: [PATCH 26/32] * sane log messages: RouterInfo.cpp --- RouterInfo.cpp | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/RouterInfo.cpp b/RouterInfo.cpp index 82b44f23..e071320c 100644 --- a/RouterInfo.cpp +++ b/RouterInfo.cpp @@ -62,7 +62,7 @@ namespace data } else { - LogPrint (eLogError, "RouterInfo signature verification failed"); + LogPrint (eLogError, "RouterInfo: signature verification failed"); m_IsUnreachable = true; } m_RouterIdentity->DropVerifier (); @@ -83,7 +83,7 @@ namespace data m_BufferLen = s.tellg (); if (m_BufferLen < 40) { - LogPrint(eLogError, "File", m_FullPath, " is malformed"); + LogPrint(eLogError, "RouterInfo: File", m_FullPath, " is malformed"); return false; } s.seekg(0, std::ios::beg); @@ -93,7 +93,7 @@ namespace data } else { - LogPrint (eLogError, "Can't open file ", m_FullPath); + LogPrint (eLogError, "RouterInfo: Can't open file ", m_FullPath); return false; } return true; @@ -117,7 +117,7 @@ namespace data int l = m_BufferLen - m_RouterIdentity->GetSignatureLen (); if (!m_RouterIdentity->Verify ((uint8_t *)m_Buffer, l, (uint8_t *)m_Buffer + l)) { - LogPrint (eLogError, "RouterInfo signature verification failed"); + LogPrint (eLogError, "RouterInfo: signature verification failed"); m_IsUnreachable = true; } m_RouterIdentity->DropVerifier (); @@ -432,7 +432,7 @@ namespace data if (!m_Buffer) { if (LoadFile ()) - LogPrint ("Buffer for ", GetIdentHashAbbreviation (GetIdentHash ()), " loaded from file"); + LogPrint (eLogDebug, "RouterInfo: Buffer for ", GetIdentHashAbbreviation (GetIdentHash ()), " loaded from file"); } return m_Buffer; } @@ -463,10 +463,10 @@ namespace data if (f.is_open ()) f.write ((char *)m_Buffer, m_BufferLen); else - LogPrint(eLogError, "Can't save RouterInfo to ", fullPath); + LogPrint(eLogError, "RouterInfo: Can't save to ", fullPath); } else - LogPrint (eLogError, "Can't save RouterInfo m_Buffer==NULL"); + LogPrint (eLogError, "RouterInfo: Can't save, m_Buffer == NULL"); } size_t RouterInfo::ReadString (char * str, std::istream& s) From ca375314f01f3acaa2490074a4ce85e996c5b030 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 14:08:12 +0000 Subject: [PATCH 27/32] * sane log messages: Identity.cpp --- Identity.cpp | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/Identity.cpp b/Identity.cpp index 78aeedd3..4b518b5b 100644 --- a/Identity.cpp +++ b/Identity.cpp @@ -101,7 +101,7 @@ namespace data break; } default: - LogPrint ("Signing key type ", (int)type, " is not supported"); + LogPrint (eLogError, "Identity: Signing key type ", (int)type, " is not supported"); } m_ExtendedLen = 4 + excessLen; // 4 bytes extra + excess length // fill certificate @@ -194,7 +194,7 @@ namespace data { if (len < DEFAULT_IDENTITY_SIZE) { - LogPrint (eLogError, "Identity buffer length ", len, " is too small"); + LogPrint (eLogError, "Identity: buffer length ", len, " is too small"); return 0; } memcpy (&m_StandardIdentity, buf, DEFAULT_IDENTITY_SIZE); @@ -210,7 +210,7 @@ namespace data } else { - LogPrint (eLogError, "Certificate length ", m_ExtendedLen, " exceeds buffer length ", len - DEFAULT_IDENTITY_SIZE); + LogPrint (eLogError, "Identity: Certificate length ", m_ExtendedLen, " exceeds buffer length ", len - DEFAULT_IDENTITY_SIZE); return 0; } } @@ -359,7 +359,7 @@ namespace data break; } default: - LogPrint ("Signing key type ", (int)keyType, " is not supported"); + LogPrint (eLogError, "Identity: Signing key type ", (int)keyType, " is not supported"); } } @@ -470,7 +470,7 @@ namespace data m_Signer.reset (new i2p::crypto::EDDSA25519Signer (m_SigningPrivateKey)); break; default: - LogPrint ("Signing key type ", (int)m_Public->GetSigningKeyType (), " is not supported"); + LogPrint (eLogError, "Identity: Signing key type ", (int)m_Public->GetSigningKeyType (), " is not supported"); } } @@ -505,7 +505,7 @@ namespace data i2p::crypto::CreateEDDSA25519RandomKeys (keys.m_SigningPrivateKey, signingPublicKey); break; default: - LogPrint ("Signing key type ", (int)type, " is not supported. Create DSA-SHA1"); + LogPrint (eLogError, "Identity: Signing key type ", (int)type, " is not supported. Create DSA-SHA1"); return PrivateKeys (i2p::data::CreateRandomKeys ()); // DSA-SHA1 } // encryption From d9af8c31a21939e328a8b2e7180e3a41512b8471 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 14:08:23 +0000 Subject: [PATCH 28/32] * sane log messages: LeaseSet.cpp --- LeaseSet.cpp | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/LeaseSet.cpp b/LeaseSet.cpp index caeec262..fb6ac60b 100644 --- a/LeaseSet.cpp +++ b/LeaseSet.cpp @@ -32,7 +32,7 @@ namespace data m_Buffer = nullptr; m_BufferLen = 0; m_IsValid = false; - LogPrint (eLogError, "Destination for local LeaseSet doesn't exist"); + LogPrint (eLogError, "LeaseSet: Destination for local LeaseSet doesn't exist"); return; } m_Buffer = new uint8_t[MAX_LS_BUFFER_SIZE]; @@ -61,7 +61,7 @@ namespace data // signature localDestination->Sign (m_Buffer, m_BufferLen, m_Buffer + m_BufferLen); m_BufferLen += localDestination->GetIdentity ()->GetSignatureLen (); - LogPrint ("Local LeaseSet of ", tunnels.size (), " leases created"); + LogPrint (eLogDebug, "LeaseSet: Local LeaseSet of ", tunnels.size (), " leases created"); ReadFromBuffer (); } @@ -90,7 +90,7 @@ namespace data size += m_Identity->GetSigningPublicKeyLen (); // unused signing key uint8_t num = m_Buffer[size]; size++; // num - LogPrint ("LeaseSet num=", (int)num); + LogPrint (eLogDebug, "LeaseSet: read num=", (int)num); if (!num) m_IsValid = false; // process leases @@ -110,7 +110,7 @@ namespace data if (!netdb.FindRouter (lease.tunnelGateway)) { // if not found request it - LogPrint (eLogInfo, "Lease's tunnel gateway not found. Requested"); + LogPrint (eLogInfo, "LeaseSet: Lease's tunnel gateway not found, requesting"); netdb.RequestDestination (lease.tunnelGateway); } } @@ -118,7 +118,7 @@ namespace data // verify if (!m_Identity->Verify (m_Buffer, leases - m_Buffer, leases)) { - LogPrint (eLogWarning, "LeaseSet verification failed"); + LogPrint (eLogWarning, "LeaseSet: verification failed"); m_IsValid = false; } } From 6c0dfc435678ecbb151aabb38e61c606a0d62f81 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 14:08:35 +0000 Subject: [PATCH 29/32] * sane log messages: Log.cpp --- Log.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Log.cpp b/Log.cpp index a25b25e8..c20e0761 100644 --- a/Log.cpp +++ b/Log.cpp @@ -49,7 +49,7 @@ void Log::SetLogFile (const std::string& fullFilePath) if (logFile->is_open ()) { SetLogStream (logFile); - LogPrint("Logging to file ", fullFilePath, " enabled."); + LogPrint(eLogInfo, "Log: will send messages to ", fullFilePath); } else delete logFile; From 7936f8730fcb2be06befb6bd6b1695f36a96c74f Mon Sep 17 00:00:00 2001 From: hagen Date: Mon, 21 Dec 2015 02:20:16 +0000 Subject: [PATCH 30/32] * sane log messages: Reseed.cpp --- Reseed.cpp | 44 ++++++++++++++++++++++---------------------- 1 file changed, 22 insertions(+), 22 deletions(-) diff --git a/Reseed.cpp b/Reseed.cpp index 0aac168f..36c16e18 100644 --- a/Reseed.cpp +++ b/Reseed.cpp @@ -54,7 +54,7 @@ namespace data int Reseeder::ReseedFromSU3 (const std::string& host, bool https) { std::string url = host + "i2pseeds.su3"; - LogPrint (eLogInfo, "Dowloading SU3 from ", host); + LogPrint (eLogInfo, "Reseed: Downloading SU3 from ", host); std::string su3 = https ? HttpsRequest (url) : i2p::util::http::httpRequest (url); if (su3.length () > 0) { @@ -63,7 +63,7 @@ namespace data } else { - LogPrint (eLogWarning, "SU3 download failed"); + LogPrint (eLogWarning, "Reseed: SU3 download failed"); return 0; } } @@ -75,7 +75,7 @@ namespace data return ProcessSU3Stream (s); else { - LogPrint (eLogError, "Can't open file ", filename); + LogPrint (eLogError, "Reseed: Can't open file ", filename); return 0; } } @@ -90,7 +90,7 @@ namespace data s.read (magicNumber, 7); // magic number and zero byte 6 if (strcmp (magicNumber, SU3_MAGIC_NUMBER)) { - LogPrint (eLogError, "Unexpected SU3 magic number"); + LogPrint (eLogError, "Reseed: Unexpected SU3 magic number"); return 0; } s.seekg (1, std::ios::cur); // su3 file format version @@ -114,7 +114,7 @@ namespace data s.read ((char *)&fileType, 1); // file type if (fileType != 0x00) // zip file { - LogPrint (eLogError, "Can't handle file type ", (int)fileType); + LogPrint (eLogError, "Reseed: Can't handle file type ", (int)fileType); return 0; } s.seekg (1, std::ios::cur); // unused @@ -122,7 +122,7 @@ namespace data s.read ((char *)&contentType, 1); // content type if (contentType != 0x03) // reseed data { - LogPrint (eLogError, "Unexpected content type ", (int)contentType); + LogPrint (eLogError, "Reseed: Unexpected content type ", (int)contentType); return 0; } s.seekg (12, std::ios::cur); // unused @@ -162,7 +162,7 @@ namespace data // digest is right aligned // we can't use RSA_verify due wrong padding in SU3 if (memcmp (enSigBuf + (signatureLength - 64), digest, 64)) - LogPrint (eLogWarning, "SU3 signature verification failed"); + LogPrint (eLogWarning, "Reseed: SU3 signature verification failed"); delete[] enSigBuf; BN_free (s); BN_free (n); BN_CTX_free (bnctx); @@ -173,10 +173,10 @@ namespace data s.seekg (pos, std::ios::beg); } else - LogPrint (eLogWarning, "Signature type ", signatureType, " is not supported"); + LogPrint (eLogWarning, "Reseed: Signature type ", signatureType, " is not supported"); } else - LogPrint (eLogWarning, "Certificate for ", signerID, " not loaded"); + LogPrint (eLogWarning, "Reseed: Certificate for ", signerID, " not loaded"); // handle content int numFiles = 0; @@ -220,7 +220,7 @@ namespace data size_t pos = s.tellg (); if (!FindZipDataDescriptor (s)) { - LogPrint (eLogError, "SU3 archive data descriptor not found"); + LogPrint (eLogError, "Reseed: SU3 archive data descriptor not found"); return numFiles; } s.read ((char *)&crc_32, 4); @@ -234,10 +234,10 @@ namespace data s.seekg (pos, std::ios::beg); // back to compressed data } - LogPrint (eLogDebug, "Proccessing file ", localFileName, " ", compressedSize, " bytes"); + LogPrint (eLogDebug, "Reseed: Proccessing file ", localFileName, " ", compressedSize, " bytes"); if (!compressedSize) { - LogPrint (eLogWarning, "Unexpected size 0. Skipped"); + LogPrint (eLogWarning, "Reseed: Unexpected size 0. Skipped"); continue; } @@ -263,10 +263,10 @@ namespace data numFiles++; } else - LogPrint (eLogError, "CRC32 verification failed"); + LogPrint (eLogError, "Reseed: CRC32 verification failed"); } else - LogPrint (eLogError, "decompression error ", err); + LogPrint (eLogError, "Reseed: SU3 decompression error ", err); delete[] uncompressed; inflateEnd (&inflator); } @@ -282,7 +282,7 @@ namespace data else { if (signature != ZIP_CENTRAL_DIRECTORY_HEADER_SIGNATURE) - LogPrint (eLogWarning, "Missing zip central directory header"); + LogPrint (eLogWarning, "Reseed: Missing zip central directory header"); break; // no more files } size_t end = s.tellg (); @@ -335,7 +335,7 @@ namespace data SSL_free (ssl); } else - LogPrint (eLogError, "Can't open certificate file ", filename); + LogPrint (eLogError, "Reseed: Can't open certificate file ", filename); SSL_CTX_free (ctx); } @@ -345,7 +345,7 @@ namespace data if (!boost::filesystem::exists (reseedDir)) { - LogPrint (eLogWarning, "Reseed certificates not loaded. ", reseedDir, " doesn't exist"); + LogPrint (eLogWarning, "Reseed: certificates not loaded, ", reseedDir, " doesn't exist"); return; } @@ -359,7 +359,7 @@ namespace data numCertificates++; } } - LogPrint (eLogInfo, numCertificates, " certificates loaded"); + LogPrint (eLogInfo, "Reseed: ", numCertificates, " certificates loaded"); } std::string Reseeder::HttpsRequest (const std::string& address) @@ -382,7 +382,7 @@ namespace data s.handshake (boost::asio::ssl::stream_base::client, ecode); if (!ecode) { - LogPrint (eLogInfo, "Connected to ", u.host_, ":", u.port_); + LogPrint (eLogInfo, "Reseed: Connected to ", u.host_, ":", u.port_); // send request std::stringstream ss; ss << "GET " << u.path_ << " HTTP/1.1\r\nHost: " << u.host_ @@ -401,13 +401,13 @@ namespace data return i2p::util::http::GetHttpContent (rs); } else - LogPrint (eLogError, "SSL handshake failed: ", ecode.message ()); + LogPrint (eLogError, "Reseed: SSL handshake failed: ", ecode.message ()); } else - LogPrint (eLogError, "Couldn't connect to ", u.host_, ": ", ecode.message ()); + LogPrint (eLogError, "Reseed: Couldn't connect to ", u.host_, ": ", ecode.message ()); } else - LogPrint (eLogError, "Couldn't resolve address ", u.host_, ": ", ecode.message ()); + LogPrint (eLogError, "Reseed: Couldn't resolve address ", u.host_, ": ", ecode.message ()); return ""; } } From d09fedf2084563c3825b329e3babf633535ef411 Mon Sep 17 00:00:00 2001 From: hagen Date: Mon, 21 Dec 2015 02:20:36 +0000 Subject: [PATCH 31/32] * sane log messages: TransitTunnel.cpp --- TransitTunnel.cpp | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/TransitTunnel.cpp b/TransitTunnel.cpp index beb09da7..81773bb5 100644 --- a/TransitTunnel.cpp +++ b/TransitTunnel.cpp @@ -45,7 +45,7 @@ namespace tunnel { auto num = m_TunnelDataMsgs.size (); if (num > 1) - LogPrint (eLogDebug, "TransitTunnel: ",GetTunnelID (),"->", GetNextTunnelID (), " ", num); + LogPrint (eLogDebug, "TransitTunnel: ", GetTunnelID (), "->", GetNextTunnelID (), " ", num); i2p::transport::transports.SendMessages (GetNextIdentHash (), m_TunnelDataMsgs); m_TunnelDataMsgs.clear (); } @@ -53,12 +53,12 @@ namespace tunnel void TransitTunnel::SendTunnelDataMsg (std::shared_ptr msg) { - LogPrint (eLogError, "We are not a gateway for transit tunnel ", GetTunnelID ()); + LogPrint (eLogError, "TransitTunnel: We are not a gateway for ", GetTunnelID ()); } void TransitTunnel::HandleTunnelDataMsg (std::shared_ptr tunnelMsg) { - LogPrint (eLogError, "Incoming tunnel message is not supported ", GetTunnelID ()); + LogPrint (eLogError, "TransitTunnel: Incoming tunnel message is not supported ", GetTunnelID ()); } void TransitTunnelGateway::SendTunnelDataMsg (std::shared_ptr msg) @@ -81,7 +81,7 @@ namespace tunnel auto newMsg = CreateEmptyTunnelDataMsg (); EncryptTunnelMsg (tunnelMsg, newMsg); - LogPrint (eLogDebug, "TransitTunnel endpoint for ", GetTunnelID ()); + LogPrint (eLogDebug, "TransitTunnel: handle msg for endpoint ", GetTunnelID ()); m_Endpoint.HandleDecryptedTunnelDataMsg (newMsg); } @@ -92,12 +92,12 @@ namespace tunnel { if (isEndpoint) { - LogPrint (eLogInfo, "TransitTunnel endpoint: ", receiveTunnelID, " created"); + LogPrint (eLogInfo, "TransitTunnel: endpoint ", receiveTunnelID, " created"); return new TransitTunnelEndpoint (receiveTunnelID, nextIdent, nextTunnelID, layerKey, ivKey); } else if (isGateway) { - LogPrint (eLogInfo, "TransitTunnel gateway: ", receiveTunnelID, " created"); + LogPrint (eLogInfo, "TransitTunnel: gateway ", receiveTunnelID, " created"); return new TransitTunnelGateway (receiveTunnelID, nextIdent, nextTunnelID, layerKey, ivKey); } else From 364ccc05d5267dd5552da907b7faf13cfe79aea9 Mon Sep 17 00:00:00 2001 From: hagen Date: Fri, 18 Dec 2015 14:30:54 +0000 Subject: [PATCH 32/32] * Log.h: drop unused template --- Log.h | 6 ------ 1 file changed, 6 deletions(-) diff --git a/Log.h b/Log.h index 8728149f..09e2156a 100644 --- a/Log.h +++ b/Log.h @@ -120,10 +120,4 @@ void LogPrint (LogLevel level, TArgs... args) } } -template -void LogPrint (TArgs... args) -{ - LogPrint (eLogInfo, args...); -} - #endif