From b3d0705e39db65c42dd5afbf215c4666fa09561b Mon Sep 17 00:00:00 2001 From: Clement Date: Wed, 8 May 2019 18:38:00 -0700 Subject: [PATCH] Extend ICE logging + make it more searchable --- assignment-client/src/AssignmentClient.cpp | 2 +- domain-server/src/DomainGatekeeper.cpp | 19 +++---- domain-server/src/DomainServer.cpp | 45 ++++++++-------- domain-server/src/DomainServer.h | 1 + interface/src/Application.cpp | 6 +-- libraries/networking/src/AddressManager.cpp | 2 +- libraries/networking/src/DomainHandler.cpp | 52 ++++++++++++------- libraries/networking/src/DomainHandler.h | 6 +-- libraries/networking/src/LimitedNodeList.cpp | 2 +- libraries/networking/src/NetworkLogging.cpp | 1 + libraries/networking/src/NetworkLogging.h | 1 + libraries/networking/src/NodeList.cpp | 30 +++++------ libraries/networking/src/NodeList.h | 4 +- .../networking/src/ThreadedAssignment.cpp | 2 +- tools/ac-client/src/ACClientApp.cpp | 2 +- tools/atp-client/src/ATPClientApp.cpp | 2 +- 16 files changed, 95 insertions(+), 82 deletions(-) diff --git a/assignment-client/src/AssignmentClient.cpp b/assignment-client/src/AssignmentClient.cpp index c1943de2cc..1ef375b562 100644 --- a/assignment-client/src/AssignmentClient.cpp +++ b/assignment-client/src/AssignmentClient.cpp @@ -307,7 +307,7 @@ void AssignmentClient::assignmentCompleted() { // reset our NodeList by switching back to unassigned and clearing the list nodeList->setOwnerType(NodeType::Unassigned); - nodeList->reset(); + nodeList->reset("Assignment completed"); nodeList->resetNodeInterestSet(); _isAssigned = false; diff --git a/domain-server/src/DomainGatekeeper.cpp b/domain-server/src/DomainGatekeeper.cpp index 8c7beaa614..e53196c67f 100644 --- a/domain-server/src/DomainGatekeeper.cpp +++ b/domain-server/src/DomainGatekeeper.cpp @@ -811,26 +811,23 @@ void DomainGatekeeper::processICEPeerInformationPacket(QSharedPointergetMessage()); - NetworkPeer* receivedPeer = new NetworkPeer; + auto receivedPeer = SharedNetworkPeer::create(); iceResponseStream >> *receivedPeer; if (!_icePeers.contains(receivedPeer->getUUID())) { - qDebug() << "New peer requesting ICE connection being added to hash -" << *receivedPeer; - SharedNetworkPeer newPeer = SharedNetworkPeer(receivedPeer); - _icePeers[receivedPeer->getUUID()] = newPeer; + qCDebug(domain_server_ice) << "New peer requesting ICE connection being added to hash -" << *receivedPeer; + _icePeers[receivedPeer->getUUID()] = receivedPeer; // make sure we know when we should ping this peer - connect(newPeer.data(), &NetworkPeer::pingTimerTimeout, this, &DomainGatekeeper::handlePeerPingTimeout); + connect(receivedPeer.data(), &NetworkPeer::pingTimerTimeout, this, &DomainGatekeeper::handlePeerPingTimeout); // immediately ping the new peer, and start a timer to continue pinging it until we connect to it - newPeer->startPingTimer(); + receivedPeer->startPingTimer(); - qDebug() << "Sending ping packets to establish connectivity with ICE peer with ID" - << newPeer->getUUID(); + qCDebug(domain_server_ice) << "Sending ping packets to establish connectivity with ICE peer with ID" + << receivedPeer->getUUID(); - pingPunchForConnectingPeer(newPeer); - } else { - delete receivedPeer; + pingPunchForConnectingPeer(receivedPeer); } } diff --git a/domain-server/src/DomainServer.cpp b/domain-server/src/DomainServer.cpp index f73c59dc32..bef6723912 100644 --- a/domain-server/src/DomainServer.cpp +++ b/domain-server/src/DomainServer.cpp @@ -58,6 +58,7 @@ #include Q_LOGGING_CATEGORY(domain_server, "hifi.domain_server") +Q_LOGGING_CATEGORY(domain_server_ice, "hifi.domain_server.ice") const QString ACCESS_TOKEN_KEY_PATH = "metaverse.access_token"; const QString DomainServer::REPLACEMENT_FILE_EXTENSION = ".replace"; @@ -374,7 +375,7 @@ void DomainServer::parseCommandLine(int argc, char* argv[]) { } if (_iceServerAddr.isEmpty()) { - qWarning() << "Could not parse an IP address and port combination from" << hostnamePortString; + qCWarning(domain_server_ice) << "Could not parse an IP address and port combination from" << hostnamePortString; ::exit(0); } } @@ -1570,12 +1571,8 @@ void DomainServer::sendICEServerAddressToMetaverseAPI() { callbackParameters.errorCallbackMethod = "handleFailedICEServerAddressUpdate"; callbackParameters.jsonCallbackMethod = "handleSuccessfulICEServerAddressUpdate"; - static bool printedIceServerMessage = false; - if (!printedIceServerMessage) { - printedIceServerMessage = true; - qDebug() << "Updating ice-server address in High Fidelity Metaverse API to" - << (_iceServerSocket.isNull() ? "" : _iceServerSocket.getAddress().toString()); - } + qCDebug(domain_server_ice) << "Updating ice-server address in High Fidelity Metaverse API to" + << (_iceServerSocket.isNull() ? "" : _iceServerSocket.getAddress().toString()); static const QString DOMAIN_ICE_ADDRESS_UPDATE = "/api/v1/domains/%1/ice_server_address"; @@ -1589,11 +1586,11 @@ void DomainServer::sendICEServerAddressToMetaverseAPI() { void DomainServer::handleSuccessfulICEServerAddressUpdate(QNetworkReply* requestReply) { _sendICEServerAddressToMetaverseAPIInProgress = false; if (_sendICEServerAddressToMetaverseAPIRedo) { - qDebug() << "ice-server address updated with metaverse, but has since changed. redoing update..."; + qCDebug(domain_server_ice) << "ice-server address updated with metaverse, but has since changed. redoing update..."; _sendICEServerAddressToMetaverseAPIRedo = false; sendICEServerAddressToMetaverseAPI(); } else { - qDebug() << "ice-server address updated with metaverse."; + qCDebug(domain_server_ice) << "ice-server address updated with metaverse."; } } @@ -1606,9 +1603,9 @@ void DomainServer::handleFailedICEServerAddressUpdate(QNetworkReply* requestRepl } else { const int ICE_SERVER_UPDATE_RETRY_MS = 2 * 1000; - qWarning() << "Failed to update ice-server address with High Fidelity Metaverse - error was" + qCWarning(domain_server_ice) << "Failed to update ice-server address with High Fidelity Metaverse - error was" << requestReply->errorString(); - qWarning() << "\tRe-attempting in" << ICE_SERVER_UPDATE_RETRY_MS / 1000 << "seconds"; + qCWarning(domain_server_ice) << "\tRe-attempting in" << ICE_SERVER_UPDATE_RETRY_MS / 1000 << "seconds"; QTimer::singleShot(ICE_SERVER_UPDATE_RETRY_MS, this, SLOT(sendICEServerAddressToMetaverseAPI())); } @@ -1621,13 +1618,13 @@ void DomainServer::sendHeartbeatToIceServer() { auto limitedNodeList = DependencyManager::get(); if (!accountManager->getAccountInfo().hasPrivateKey()) { - qWarning() << "Cannot send an ice-server heartbeat without a private key for signature."; - qWarning() << "Waiting for keypair generation to complete before sending ICE heartbeat."; + qCWarning(domain_server_ice) << "Cannot send an ice-server heartbeat without a private key for signature."; + qCWarning(domain_server_ice) << "Waiting for keypair generation to complete before sending ICE heartbeat."; if (!limitedNodeList->getSessionUUID().isNull()) { accountManager->generateNewDomainKeypair(limitedNodeList->getSessionUUID()); } else { - qWarning() << "Attempting to send ICE server heartbeat with no domain ID. This is not supported"; + qCWarning(domain_server_ice) << "Attempting to send ICE server heartbeat with no domain ID. This is not supported"; } return; @@ -1639,8 +1636,8 @@ void DomainServer::sendHeartbeatToIceServer() { ++_noReplyICEHeartbeats; if (_noReplyICEHeartbeats > FAILOVER_NO_REPLY_ICE_HEARTBEATS) { - qWarning() << "There have been" << _noReplyICEHeartbeats - 1 << "heartbeats sent with no reply from the ice-server"; - qWarning() << "Clearing the current ice-server socket and selecting a new candidate ice-server"; + qCWarning(domain_server_ice) << "There have been" << _noReplyICEHeartbeats - 1 << "heartbeats sent with no reply from the ice-server"; + qCWarning(domain_server_ice) << "Clearing the current ice-server socket and selecting a new candidate ice-server"; // add the current address to our list of failed addresses _failedIceServerAddresses << _iceServerSocket.getAddress(); @@ -1713,8 +1710,8 @@ void DomainServer::sendHeartbeatToIceServer() { limitedNodeList->sendUnreliablePacket(*_iceServerHeartbeatPacket, _iceServerSocket); } else { - qDebug() << "Not sending ice-server heartbeat since there is no selected ice-server."; - qDebug() << "Waiting for" << _iceServerAddr << "host lookup response"; + qCDebug(domain_server_ice) << "Not sending ice-server heartbeat since there is no selected ice-server."; + qCDebug(domain_server_ice) << "Waiting for" << _iceServerAddr << "host lookup response"; } } @@ -3294,7 +3291,7 @@ void DomainServer::processICEServerHeartbeatDenialPacket(QSharedPointer NUM_HEARTBEAT_DENIALS_FOR_KEYPAIR_REGEN) { - qDebug() << "Received" << NUM_HEARTBEAT_DENIALS_FOR_KEYPAIR_REGEN << "heartbeat denials from ice-server" + qCDebug(domain_server_ice) << "Received" << NUM_HEARTBEAT_DENIALS_FOR_KEYPAIR_REGEN << "heartbeat denials from ice-server" << "- re-generating keypair now"; // we've hit our threshold of heartbeat denials, trigger a keypair re-generation @@ -3316,7 +3313,7 @@ void DomainServer::processICEServerHeartbeatACK(QSharedPointer if (!_connectedToICEServer) { _connectedToICEServer = true; sendICEServerAddressToMetaverseAPI(); - qInfo() << "Connected to ice-server at" << _iceServerSocket; + qCInfo(domain_server_ice) << "Connected to ice-server at" << _iceServerSocket; } } @@ -3347,7 +3344,7 @@ void DomainServer::handleICEHostInfo(const QHostInfo& hostInfo) { } if (hostInfo.error() != QHostInfo::NoError || sanitizedAddresses.empty()) { - qWarning() << "IP address lookup failed for" << _iceServerAddr << ":" << hostInfo.errorString(); + qCWarning(domain_server_ice) << "IP address lookup failed for" << _iceServerAddr << ":" << hostInfo.errorString(); // if we don't have an ICE server to use yet, trigger a retry if (_iceServerSocket.isNull()) { @@ -3362,7 +3359,7 @@ void DomainServer::handleICEHostInfo(const QHostInfo& hostInfo) { _iceServerAddresses = sanitizedAddresses; if (countBefore == 0) { - qInfo() << "Found" << _iceServerAddresses.count() << "ice-server IP addresses for" << _iceServerAddr; + qCInfo(domain_server_ice) << "Found" << _iceServerAddresses.count() << "ice-server IP addresses for" << _iceServerAddr; } if (_iceServerSocket.isNull()) { @@ -3396,7 +3393,7 @@ void DomainServer::randomizeICEServerAddress(bool shouldTriggerHostLookup) { // we ended up with an empty list since everything we've tried has failed // so clear the set of failed addresses and start going through them again - qWarning() << "All current ice-server addresses have failed - re-attempting all current addresses for" + qCWarning(domain_server_ice) << "All current ice-server addresses have failed - re-attempting all current addresses for" << _iceServerAddr; _failedIceServerAddresses.clear(); @@ -3416,7 +3413,7 @@ void DomainServer::randomizeICEServerAddress(bool shouldTriggerHostLookup) { } _iceServerSocket = HifiSockAddr { candidateICEAddresses[indexToTry], ICE_SERVER_DEFAULT_PORT }; - qInfo() << "Set candidate ice-server socket to" << _iceServerSocket; + qCInfo(domain_server_ice) << "Set candidate ice-server socket to" << _iceServerSocket; // clear our number of hearbeat denials, this should be re-set on ice-server change _numHeartbeatDenials = 0; diff --git a/domain-server/src/DomainServer.h b/domain-server/src/DomainServer.h index f0c20241a2..8276566233 100644 --- a/domain-server/src/DomainServer.h +++ b/domain-server/src/DomainServer.h @@ -40,6 +40,7 @@ #include Q_DECLARE_LOGGING_CATEGORY(domain_server) +Q_DECLARE_LOGGING_CATEGORY(domain_server_ice) typedef QSharedPointer SharedAssignmentPointer; typedef QMultiHash TransactionHash; diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index d84c3e8b85..baa0e2037f 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -2688,7 +2688,7 @@ void Application::cleanupBeforeQuit() { auto nodeList = DependencyManager::get(); // send the domain a disconnect packet, force stoppage of domain-server check-ins - nodeList->getDomainHandler().disconnect(); + nodeList->getDomainHandler().disconnect("Quitting"); nodeList->setIsShuttingDown(true); // tell the packet receiver we're shutting down, so it can drop packets @@ -5537,7 +5537,7 @@ void Application::pauseUntilLoginDetermined() { cameraModeChanged(); // disconnect domain handler. - nodeList->getDomainHandler().disconnect(); + nodeList->getDomainHandler().disconnect("Pause until login determined"); // From now on, it's permissible to call resumeAfterLoginDialogActionTaken() _resumeAfterLoginDialogActionTaken_SafeToRun = true; @@ -5916,7 +5916,7 @@ void Application::reloadResourceCaches() { DependencyManager::get()->refreshAll(); DependencyManager::get()->refreshAll(); - DependencyManager::get()->reset(); // Force redownload of .fst models + DependencyManager::get()->reset("Reloading resources"); // Force redownload of .fst models DependencyManager::get()->reloadAllScripts(); getOffscreenUI()->clearCache(); diff --git a/libraries/networking/src/AddressManager.cpp b/libraries/networking/src/AddressManager.cpp index 517daf8ce5..7b21cb3460 100644 --- a/libraries/networking/src/AddressManager.cpp +++ b/libraries/networking/src/AddressManager.cpp @@ -482,7 +482,7 @@ void AddressManager::goToAddressFromObject(const QVariantMap& dataObject, const } else { QString iceServerAddress = domainObject[DOMAIN_ICE_SERVER_ADDRESS_KEY].toString(); - qCDebug(networking) << "Possible domain change required to connect to domain with ID" << domainID + qCDebug(networking_ice) << "Possible domain change required to connect to domain with ID" << domainID << "via ice-server at" << iceServerAddress; emit possibleDomainChangeRequiredViaICEForID(iceServerAddress, domainID); diff --git a/libraries/networking/src/DomainHandler.cpp b/libraries/networking/src/DomainHandler.cpp index 2513510b05..7793963959 100644 --- a/libraries/networking/src/DomainHandler.cpp +++ b/libraries/networking/src/DomainHandler.cpp @@ -64,7 +64,7 @@ DomainHandler::DomainHandler(QObject* parent) : connect(this, &DomainHandler::redirectToErrorDomainURL, &_apiRefreshTimer, &QTimer::stop); } -void DomainHandler::disconnect() { +void DomainHandler::disconnect(QString reason) { // if we're currently connected to a domain, send a disconnect packet on our way out if (_isConnected) { sendDisconnectPacket(); @@ -81,6 +81,8 @@ void DomainHandler::disconnect() { _sockAddr.clear(); } + qCDebug(networking_ice) << "Disconnecting from domain server."; + qCDebug(networking_ice) << "REASON:" << reason; setIsConnected(false); } @@ -100,9 +102,9 @@ void DomainHandler::clearSettings() { _settingsObject = QJsonObject(); } -void DomainHandler::softReset() { +void DomainHandler::softReset(QString reason) { qCDebug(networking) << "Resetting current domain connection information."; - disconnect(); + disconnect(reason); clearSettings(); @@ -118,10 +120,10 @@ void DomainHandler::softReset() { } } -void DomainHandler::hardReset() { +void DomainHandler::hardReset(QString reason) { emit resetting(); - softReset(); + softReset(reason); _isInErrorState = false; emit redirectErrorStateChanged(_isInErrorState); @@ -166,7 +168,7 @@ void DomainHandler::setErrorDomainURL(const QUrl& url) { void DomainHandler::setSockAddr(const HifiSockAddr& sockAddr, const QString& hostname) { if (_sockAddr != sockAddr) { // we should reset on a sockAddr change - hardReset(); + hardReset("Changing domain sockAddr"); // change the sockAddr _sockAddr = sockAddr; } @@ -209,7 +211,7 @@ void DomainHandler::setURLAndID(QUrl domainURL, QUuid domainID) { // if it's in the error state, reset and try again. if ((_domainURL != domainURL || _sockAddr.getPort() != domainPort) || _isInErrorState) { // re-set the domain info so that auth information is reloaded - hardReset(); + hardReset("Changing domain URL"); QString previousHost = _domainURL.host(); _domainURL = domainURL; @@ -242,10 +244,24 @@ void DomainHandler::setURLAndID(QUrl domainURL, QUuid domainID) { void DomainHandler::setIceServerHostnameAndID(const QString& iceServerHostname, const QUuid& id) { + auto newIceServer = _iceServerSockAddr.getAddress().toString() != iceServerHostname; + auto newDomainID = id != _pendingDomainID; + // if it's in the error state, reset and try again. - if ((_iceServerSockAddr.getAddress().toString() != iceServerHostname || id != _pendingDomainID) || _isInErrorState) { + if (newIceServer || newDomainID || _isInErrorState) { + QString reason; + if (newIceServer) { + reason += "New ICE server;"; + } + if (newDomainID) { + reason += "New domain ID;"; + } + if (_isInErrorState) { + reason += "Domain in error state;"; + } + // re-set the domain info to connect to new domain - hardReset(); + hardReset(reason); // refresh our ICE client UUID to something new _iceClientID = QUuid::createUuid(); @@ -268,7 +284,7 @@ void DomainHandler::setIceServerHostnameAndID(const QString& iceServerHostname, completedIceServerHostnameLookup(); } - qCDebug(networking) << "ICE required to connect to domain via ice server at" << iceServerHostname; + qCDebug(networking_ice) << "ICE required to connect to domain via ice server at" << iceServerHostname; } } @@ -322,7 +338,7 @@ void DomainHandler::completedHostnameLookup(const QHostInfo& hostInfo) { } void DomainHandler::completedIceServerHostnameLookup() { - qCDebug(networking) << "ICE server socket is at" << _iceServerSockAddr; + qCDebug(networking_ice) << "ICE server socket is at" << _iceServerSockAddr; DependencyManager::get()->flagTimeForConnectionStep(LimitedNodeList::ConnectionStep::SetICEServerSocket); @@ -409,7 +425,7 @@ void DomainHandler::processSettingsPacketList(QSharedPointer pa void DomainHandler::processICEPingReplyPacket(QSharedPointer message) { const HifiSockAddr& senderSockAddr = message->getSenderSockAddr(); - qCDebug(networking) << "Received reply from domain-server on" << senderSockAddr; + qCDebug(networking_ice) << "Received reply from domain-server on" << senderSockAddr; if (getIP().isNull()) { // we're hearing back from this domain-server, no need to refresh API information @@ -417,13 +433,13 @@ void DomainHandler::processICEPingReplyPacket(QSharedPointer me // for now we're unsafely assuming this came back from the domain if (senderSockAddr == _icePeer.getLocalSocket()) { - qCDebug(networking) << "Connecting to domain using local socket"; + qCDebug(networking_ice) << "Connecting to domain using local socket"; activateICELocalSocket(); } else if (senderSockAddr == _icePeer.getPublicSocket()) { - qCDebug(networking) << "Conecting to domain using public socket"; + qCDebug(networking_ice) << "Conecting to domain using public socket"; activateICEPublicSocket(); } else { - qCDebug(networking) << "Reply does not match either local or public socket for domain. Will not connect."; + qCDebug(networking_ice) << "Reply does not match either local or public socket for domain. Will not connect."; } } } @@ -442,7 +458,7 @@ void DomainHandler::processDTLSRequirementPacket(QSharedPointer void DomainHandler::processICEResponsePacket(QSharedPointer message) { if (_icePeer.hasSockets()) { - qCDebug(networking) << "Received an ICE peer packet for domain-server but we already have sockets. Not processing."; + qCDebug(networking_ice) << "Received an ICE peer packet for domain-server but we already have sockets. Not processing."; // bail on processing this packet if our ice peer already has sockets return; } @@ -457,10 +473,10 @@ void DomainHandler::processICEResponsePacket(QSharedPointer mes DependencyManager::get()->flagTimeForConnectionStep(LimitedNodeList::ConnectionStep::ReceiveDSPeerInformation); if (_icePeer.getUUID() != _pendingDomainID) { - qCDebug(networking) << "Received a network peer with ID that does not match current domain. Will not attempt connection."; + qCDebug(networking_ice) << "Received a network peer with ID that does not match current domain. Will not attempt connection."; _icePeer.reset(); } else { - qCDebug(networking) << "Received network peer object for domain -" << _icePeer; + qCDebug(networking_ice) << "Received network peer object for domain -" << _icePeer; // ask the peer object to start its ping timer _icePeer.startPingTimer(); diff --git a/libraries/networking/src/DomainHandler.h b/libraries/networking/src/DomainHandler.h index 620ffb9641..fb18866001 100644 --- a/libraries/networking/src/DomainHandler.h +++ b/libraries/networking/src/DomainHandler.h @@ -42,7 +42,7 @@ class DomainHandler : public QObject { public: DomainHandler(QObject* parent = 0); - void disconnect(); + void disconnect(QString reason); void clearSettings(); const QUuid& getUUID() const { return _uuid; } @@ -105,7 +105,7 @@ public: bool isSocketKnown() const { return !_sockAddr.getAddress().isNull(); } - void softReset(); + void softReset(QString reason); int getCheckInPacketsSinceLastReply() const { return _checkInPacketsSinceLastReply; } bool checkInPacketTimeout(); @@ -210,7 +210,7 @@ signals: private: bool reasonSuggestsLogin(ConnectionRefusedReason reasonCode); void sendDisconnectPacket(); - void hardReset(); + void hardReset(QString reason); bool isHardRefusal(int reasonCode); diff --git a/libraries/networking/src/LimitedNodeList.cpp b/libraries/networking/src/LimitedNodeList.cpp index 82f3459c15..cc0ef8ae17 100644 --- a/libraries/networking/src/LimitedNodeList.cpp +++ b/libraries/networking/src/LimitedNodeList.cpp @@ -1265,7 +1265,7 @@ void LimitedNodeList::sendPacketToIceServer(PacketType packetType, const HifiSoc iceDataStream << peerID; - qCDebug(networking) << "Sending packet to ICE server to request connection info for peer with ID" + qCDebug(networking_ice) << "Sending packet to ICE server to request connection info for peer with ID" << uuidStringWithoutCurlyBraces(peerID); } diff --git a/libraries/networking/src/NetworkLogging.cpp b/libraries/networking/src/NetworkLogging.cpp index 834398694d..3d7c2fc5d5 100644 --- a/libraries/networking/src/NetworkLogging.cpp +++ b/libraries/networking/src/NetworkLogging.cpp @@ -12,6 +12,7 @@ #include "NetworkLogging.h" Q_LOGGING_CATEGORY(networking, "hifi.networking") +Q_LOGGING_CATEGORY(networking_ice, "hifi.networking.ice") Q_LOGGING_CATEGORY(resourceLog, "hifi.networking.resource") Q_LOGGING_CATEGORY(asset_client, "hifi.networking.asset_client") Q_LOGGING_CATEGORY(messages_client, "hifi.networking.messages_client") diff --git a/libraries/networking/src/NetworkLogging.h b/libraries/networking/src/NetworkLogging.h index 30116ff405..8247c60096 100644 --- a/libraries/networking/src/NetworkLogging.h +++ b/libraries/networking/src/NetworkLogging.h @@ -16,6 +16,7 @@ Q_DECLARE_LOGGING_CATEGORY(resourceLog) Q_DECLARE_LOGGING_CATEGORY(networking) +Q_DECLARE_LOGGING_CATEGORY(networking_ice) Q_DECLARE_LOGGING_CATEGORY(asset_client) Q_DECLARE_LOGGING_CATEGORY(messages_client) diff --git a/libraries/networking/src/NodeList.cpp b/libraries/networking/src/NodeList.cpp index 0a4c63d712..5093cc8f62 100644 --- a/libraries/networking/src/NodeList.cpp +++ b/libraries/networking/src/NodeList.cpp @@ -243,9 +243,11 @@ void NodeList::processICEPingPacket(QSharedPointer message) { sendPacket(std::move(replyPacket), message->getSenderSockAddr()); } -void NodeList::reset(bool skipDomainHandlerReset) { +void NodeList::reset(QString reason, bool skipDomainHandlerReset) { if (thread() != QThread::currentThread()) { - QMetaObject::invokeMethod(this, "reset", Q_ARG(bool, skipDomainHandlerReset)); + QMetaObject::invokeMethod(this, "reset", + Q_ARG(QString, reason), + Q_ARG(bool, skipDomainHandlerReset)); return; } @@ -267,7 +269,7 @@ void NodeList::reset(bool skipDomainHandlerReset) { if (!skipDomainHandlerReset) { // clear the domain connection information, unless they're the ones that asked us to reset - _domainHandler.softReset(); + _domainHandler.softReset(reason); } // refresh the owner UUID to the NULL UUID @@ -297,12 +299,12 @@ void NodeList::sendDomainServerCheckIn() { // may be called by multiple threads. if (!_sendDomainServerCheckInEnabled) { - qCDebug(networking) << "Refusing to send a domain-server check in while it is disabled."; + qCDebug(networking_ice) << "Refusing to send a domain-server check in while it is disabled."; return; } if (_isShuttingDown) { - qCDebug(networking) << "Refusing to send a domain-server check in while shutting down."; + qCDebug(networking_ice) << "Refusing to send a domain-server check in while shutting down."; return; } @@ -311,9 +313,9 @@ void NodeList::sendDomainServerCheckIn() { if (publicSockAddr.isNull()) { // we don't know our public socket and we need to send it to the domain server - qCDebug(networking) << "Waiting for inital public socket from STUN. Will not send domain-server check in."; + qCDebug(networking_ice) << "Waiting for inital public socket from STUN. Will not send domain-server check in."; } else if (domainHandlerIp.isNull() && _domainHandler.requiresICE()) { - qCDebug(networking) << "Waiting for ICE discovered domain-server socket. Will not send domain-server check in."; + qCDebug(networking_ice) << "Waiting for ICE discovered domain-server socket. Will not send domain-server check in."; handleICEConnectionToDomainServer(); // let the domain handler know we are due to send a checkin packet } else if (!domainHandlerIp.isNull() && !_domainHandler.checkInPacketTimeout()) { @@ -324,7 +326,7 @@ void NodeList::sendDomainServerCheckIn() { if (!domainIsConnected) { auto hostname = _domainHandler.getHostname(); - qCDebug(networking) << "Sending connect request to domain-server at" << hostname; + qCDebug(networking_ice) << "Sending connect request to domain-server at" << hostname; // is this our localhost domain-server? // if so we need to make sure we have an up-to-date local port in case it restarted @@ -334,7 +336,7 @@ void NodeList::sendDomainServerCheckIn() { quint16 domainPort = DEFAULT_DOMAIN_SERVER_PORT; getLocalServerPortFromSharedMemory(DOMAIN_SERVER_LOCAL_PORT_SMEM_KEY, domainPort); - qCDebug(networking) << "Local domain-server port read from shared memory (or default) is" << domainPort; + qCDebug(networking_ice) << "Local domain-server port read from shared memory (or default) is" << domainPort; _domainHandler.setPort(domainPort); } } @@ -346,7 +348,7 @@ void NodeList::sendDomainServerCheckIn() { bool requiresUsernameSignature = !domainIsConnected && !connectionToken.isNull(); if (requiresUsernameSignature && !accountManager->getAccountInfo().hasPrivateKey()) { - qWarning() << "A keypair is required to present a username signature to the domain-server" + qCWarning(networking_ice) << "A keypair is required to present a username signature to the domain-server" << "but no keypair is present. Waiting for keypair generation to complete."; accountManager->generateNewUserKeypair(); @@ -574,12 +576,12 @@ void NodeList::pingPunchForDomainServer() { const int NUM_DOMAIN_SERVER_PINGS_BEFORE_RESET = 2000 / UDP_PUNCH_PING_INTERVAL_MS; if (_domainHandler.getICEPeer().getConnectionAttempts() == 0) { - qCDebug(networking) << "Sending ping packets to establish connectivity with domain-server with ID" + qCDebug(networking_ice) << "Sending ping packets to establish connectivity with domain-server with ID" << uuidStringWithoutCurlyBraces(_domainHandler.getPendingDomainID()); } else { if (_domainHandler.getICEPeer().getConnectionAttempts() % NUM_DOMAIN_SERVER_PINGS_BEFORE_RESET == 0) { // if we have then nullify the domain handler's network peer and send a fresh ICE heartbeat - qCDebug(networking) << "No ping replies received from domain-server with ID" + qCDebug(networking_ice) << "No ping replies received from domain-server with ID" << uuidStringWithoutCurlyBraces(_domainHandler.getICEClientID()) << "-" << "re-sending ICE query."; _domainHandler.getICEPeer().softReset(); @@ -657,10 +659,8 @@ void NodeList::processDomainServerList(QSharedPointer message) if (_domainHandler.isConnected() && ((currentLocalID != Node::NULL_LOCAL_ID && newLocalID != currentLocalID) || (!currentSessionID.isNull() && newUUID != currentSessionID))) { - qCDebug(networking) << "Local ID or Session ID changed while connected to domain - forcing NodeList reset"; - // reset the nodelist, but don't do a domain handler reset since we're about to process a good domain list - reset(true); + reset("Local ID or Session ID changed while connected to domain - forcing NodeList reset", true); // tell the domain handler that we're no longer connected so that below // it can re-perform actions as if we just connected diff --git a/libraries/networking/src/NodeList.h b/libraries/networking/src/NodeList.h index f871560fba..c377ea89cb 100644 --- a/libraries/networking/src/NodeList.h +++ b/libraries/networking/src/NodeList.h @@ -103,8 +103,8 @@ public: virtual HifiSockAddr getDomainSockAddr() const override { return _domainHandler.getSockAddr(); } public slots: - void reset(bool skipDomainHandlerReset = false); - void resetFromDomainHandler() { reset(true); } + void reset(QString reason, bool skipDomainHandlerReset = false); + void resetFromDomainHandler() { reset("Reset from Domain Handler", true); } void sendDomainServerCheckIn(); void handleDSPathQuery(const QString& newPath); diff --git a/libraries/networking/src/ThreadedAssignment.cpp b/libraries/networking/src/ThreadedAssignment.cpp index 9b9a53b469..6a29613d25 100644 --- a/libraries/networking/src/ThreadedAssignment.cpp +++ b/libraries/networking/src/ThreadedAssignment.cpp @@ -58,7 +58,7 @@ void ThreadedAssignment::setFinished(bool isFinished) { packetReceiver.setShouldDropPackets(true); // send a disconnect packet to the domain - nodeList->getDomainHandler().disconnect(); + nodeList->getDomainHandler().disconnect("Finished"); // stop our owned timers _domainServerTimer.stop(); diff --git a/tools/ac-client/src/ACClientApp.cpp b/tools/ac-client/src/ACClientApp.cpp index cfede87c53..6b781a5bea 100644 --- a/tools/ac-client/src/ACClientApp.cpp +++ b/tools/ac-client/src/ACClientApp.cpp @@ -263,7 +263,7 @@ void ACClientApp::finish(int exitCode) { auto nodeList = DependencyManager::get(); // send the domain a disconnect packet, force stoppage of domain-server check-ins - nodeList->getDomainHandler().disconnect(); + nodeList->getDomainHandler().disconnect("Finishing"); nodeList->setIsShuttingDown(true); // tell the packet receiver we're shutting down, so it can drop packets diff --git a/tools/atp-client/src/ATPClientApp.cpp b/tools/atp-client/src/ATPClientApp.cpp index c688ba9c82..8c2fd44adf 100644 --- a/tools/atp-client/src/ATPClientApp.cpp +++ b/tools/atp-client/src/ATPClientApp.cpp @@ -394,7 +394,7 @@ void ATPClientApp::finish(int exitCode) { auto nodeList = DependencyManager::get(); // send the domain a disconnect packet, force stoppage of domain-server check-ins - nodeList->getDomainHandler().disconnect(); + nodeList->getDomainHandler().disconnect("Finishing"); nodeList->setIsShuttingDown(true); // tell the packet receiver we're shutting down, so it can drop packets