C++ Log_debug函数代码示例

/*
 * Send a ping packet to one of the endpoints.
 */
static void sendPing(struct InterfaceController_Peer* ep)
{
    struct InterfaceController_pvt* ic = ifcontrollerForPeer(ep);

    ep->pingCount++;

    struct SwitchPinger_Ping* ping =
        SwitchPinger_newPing(ep->switchLabel,
                             String_CONST(""),
                             ic->timeoutMilliseconds,
                             onPingResponse,
                             ic->allocator,
                             ic->switchPinger);

    #ifdef Log_DEBUG
        uint8_t key[56];
        Base32_encode(key, 56, CryptoAuth_getHerPublicKey(ep->cryptoAuthIf), 32);
    #endif
    if (!ping) {
        Log_debug(ic->logger, "Failed to ping [%s.k], out of ping slots", key);
        return;
    } else {
        Log_debug(ic->logger, "SwitchPing [%s.k]", key);
    }

    ping->onResponseContext = ep;
}

static inline bool decryptMessage(struct CryptoAuth_Wrapper* wrapper,
                                  uint32_t nonce,
                                  struct Message* content,
                                  uint8_t secret[32])
{
    if (wrapper->authenticatePackets) {
        // Decrypt with authentication and replay prevention.
        int ret = decrypt(nonce, content, secret, wrapper->isInitiator, true);
        if (ret) {
            Log_debug(wrapper->context->logger,
                       "Authenticated decryption failed returning %u\n",
                       ret);
            return false;
        }
        ret = !ReplayProtector_checkNonce(nonce, &wrapper->replayProtector);
        if (ret) {
            Log_debug(wrapper->context->logger, "Nonce checking failed.\n");
            return false;
        }
    } else {
        decrypt(nonce, content, secret, wrapper->isInitiator, false);
    }
    int ret = callReceivedMessage(wrapper, content);
    if (ret) {
        Log_debug(wrapper->context->logger,
                   "Call received message failed returning %u\n",
                   ret);
        return false;
    }
    return true;
}

static void checkLinkage(void* vTwoNodes)
{
    struct TwoNodes* ctx = Identity_check((struct TwoNodes*) vTwoNodes);

    if (!ctx->beaconsSent) {
        if (Pathfinder_getNodeStore(ctx->nodeA->pathfinder) &&
            Pathfinder_getNodeStore(ctx->nodeB->pathfinder))
        {
            Log_debug(ctx->logger, "Linking A and B");
            TestFramework_linkNodes(ctx->nodeB, ctx->nodeA, true);
            ctx->beaconsSent = true;
        }
        return;
    }


    if (Pathfinder_getNodeStore(ctx->nodeA->pathfinder)->nodeCount < 1) {
        notLinkedYet(ctx);
        return;
    }
    Log_debug(ctx->logger, "A seems to be linked with B");
    if (Pathfinder_getNodeStore(ctx->nodeB->pathfinder)->nodeCount < 1) {
        notLinkedYet(ctx);
        return;
    }
    Log_debug(ctx->logger, "B seems to be linked with A");
    Log_debug(ctx->logger, "\n\nSetup Complete\n\n");

    Timeout_clearTimeout(ctx->checkLinkageTimeout);

    ctx->runTest(ctx);
}

static void ipTunnel(Dict* ifaceConf, struct Allocator* tempAlloc, struct Context* ctx)
{
    List* incoming = Dict_getList(ifaceConf, String_CONST("allowedConnections"));
    Dict* d;
    for (int i = 0; (d = List_getDict(incoming, i)) != NULL; i++) {
        String* key = Dict_getString(d, String_CONST("publicKey"));
        String* ip4 = Dict_getString(d, String_CONST("ip4Address"));
        String* ip6 = Dict_getString(d, String_CONST("ip6Address"));
        if (!key) {
            Log_critical(ctx->logger, "In router.ipTunnel.allowedConnections[%d]"
                                      "'publicKey' required.", i);
            exit(1);
        }
        if (!ip4 && !ip6) {
            Log_critical(ctx->logger, "In router.ipTunnel.allowedConnections[%d]"
                                       "either ip4Address or ip6Address required.", i);
            exit(1);
        }
        Log_debug(ctx->logger, "Allowing IpTunnel connections from [%s]", key->bytes);
        Dict_putString(d, String_CONST("publicKeyOfAuthorizedNode"), key, tempAlloc);
        rpcCall0(String_CONST("IpTunnel_allowConnection"), d, ctx, tempAlloc, true);
    }

    List* outgoing = Dict_getList(ifaceConf, String_CONST("outgoingConnections"));
    String* s;
    for (int i = 0; (s = List_getString(outgoing, i)) != NULL; i++) {
        Log_debug(ctx->logger, "Initiating IpTunnel connection to [%s]", s->bytes);
        Dict requestDict =
            Dict_CONST(String_CONST("publicKeyOfNodeToConnectTo"), String_OBJ(s), NULL);
        rpcCall0(String_CONST("IpTunnel_connectTo"), &requestDict, ctx, tempAlloc, true);
    }
}

/**
 * If we don't know her key, the handshake has to be done backwards.
 * Reverse handshake requests are signaled by sending a non-obfuscated zero nonce.
 */
static uint8_t genReverseHandshake(struct Message* message,
                                   struct Wrapper* wrapper,
                                   union Headers_CryptoAuth* header)
{
    wrapper->nextNonce = 0;
    Message_shift(message, -Headers_CryptoAuth_SIZE);

    // Buffer the packet so it can be sent ASAP
    if (wrapper->bufferedMessage == NULL) {
        Log_debug(wrapper->context->logger, "Buffered a message.\n");
        wrapper->bufferedMessage =
            Message_clone(message, wrapper->externalInterface.allocator);
        assert(wrapper->nextNonce == 0);
    } else {
        Log_debug(wrapper->context->logger,
                  "Expelled a message because a session has not yet been setup.\n");
        Message_copyOver(wrapper->bufferedMessage,
                         message,
                         wrapper->externalInterface.allocator);
        assert(wrapper->nextNonce == 0);
    }
    wrapper->hasBufferedMessage = true;

    Message_shift(message, Headers_CryptoAuth_SIZE);
    header = (union Headers_CryptoAuth*) message->bytes;
    header->nonce = UINT32_MAX;
    message->length = Headers_CryptoAuth_SIZE;

    // sessionState must be 0, auth and 24 byte nonce are garbaged and public key is set
    // now garbage the authenticator and the encrypted key which are not used.
    randombytes((uint8_t*) &header->handshake.authenticator, 48);

    return wrapper->wrappedInterface->sendMessage(message, wrapper->wrappedInterface);
}

static void search(uint8_t target[16], struct Janitor* janitor)
{
    if (janitor->searches >= MAX_SEARCHES) {
        Log_debug(janitor->logger, "Skipping search because 20 are in progress");
        return;
    }
    #ifdef Log_DEBUG
        uint8_t targetStr[40];
        AddrTools_printIp(targetStr, target);
        Log_debug(janitor->logger, "Beginning search for [%s]", targetStr);
    #endif

    struct Allocator* searchAlloc = Allocator_child(janitor->allocator);
    struct RouterModule_Promise* rp =
        SearchRunner_search(target, janitor->searchRunner, searchAlloc);

    if (!rp) {
        Log_debug(janitor->logger, "SearchRunner_search() returned NULL, probably full.");
        Allocator_free(searchAlloc);
        return;
    }

    janitor->searches++;

    struct Janitor_Search* search = Allocator_clone(rp->alloc, (&(struct Janitor_Search) {
        .janitor = janitor,
        .alloc = searchAlloc,
    }));

/*
 * Send a ping packet to one of the endpoints.
 */
static void sendPing(struct Peer* ep)
{
    struct InterfaceController_pvt* ic = Identity_check(ep->ici->ic);

    ep->pingCount++;

    struct SwitchPinger_Ping* ping =
        SwitchPinger_newPing(ep->addr.path,
                             String_CONST(""),
                             ic->timeoutMilliseconds,
                             onPingResponse,
                             ep->alloc,
                             ic->switchPinger);

    if (Defined(Log_DEBUG)) {
        uint8_t key[56];
        Base32_encode(key, 56, ep->caSession->herPublicKey, 32);
        if (!ping) {
            Log_debug(ic->logger, "Failed to ping [%s.k], out of ping slots", key);
        } else {
            Log_debug(ic->logger, "SwitchPing [%s.k]", key);
        }
    }

    if (ping) {
        ping->onResponseContext = ep;
    }
}

Iface_DEFUN TUNTools_genericIP6Echo(struct Message* msg, struct TUNTools* tt)
{
    uint16_t ethertype = TUNMessageType_pop(msg, NULL);
    if (ethertype != Ethernet_TYPE_IP6) {
        Log_debug(tt->log, "Spurious packet with ethertype [%04x]\n",
                  Endian_bigEndianToHost16(ethertype));
        return 0;
    }

    struct Headers_IP6Header* header = (struct Headers_IP6Header*) msg->bytes;

    if (msg->length != Headers_IP6Header_SIZE + Headers_UDPHeader_SIZE + 12) {
        int type = (msg->length >= Headers_IP6Header_SIZE) ? header->nextHeader : -1;
        Log_debug(tt->log, "Message of unexpected length [%u] ip6->nextHeader: [%d]\n",
                  msg->length, type);
        return 0;
    }
    uint8_t* address;
    Sockaddr_getAddress(tt->tunDestAddr, &address);
    Assert_true(!Bits_memcmp(header->destinationAddr, address, 16));
    Sockaddr_getAddress(tt->udpBindTo, &address);
    Assert_true(!Bits_memcmp(header->sourceAddr, address, 16));

    Sockaddr_getAddress(tt->udpBindTo, &address);
    Bits_memcpy(header->destinationAddr, address, 16);
    Sockaddr_getAddress(tt->tunDestAddr, &address);
    Bits_memcpy(header->sourceAddr, address, 16);

    TUNMessageType_push(msg, ethertype, NULL);

    return Iface_next(&tt->tunIface, msg);
}

static void sendBeacon(struct InterfaceController_Iface_pvt* ici, struct Allocator* tempAlloc)
{
    if (ici->beaconState < InterfaceController_beaconState_newState_SEND) {
        Log_debug(ici->ic->logger, "sendBeacon(%s) -> beaconing disabled", ici->name->bytes);
        return;
    }

    Log_debug(ici->ic->logger, "sendBeacon(%s)", ici->name->bytes);

    struct Message* msg = Message_new(0, 128, tempAlloc);
    Message_push(msg, &ici->ic->beacon, Headers_Beacon_SIZE, NULL);

    if (Defined(Log_DEBUG)) {
        char* content = Hex_print(msg->bytes, msg->length, tempAlloc);
        Log_debug(ici->ic->logger, "SEND BEACON CONTENT[%s]", content);
    }

    struct Sockaddr sa = {
        .addrLen = Sockaddr_OVERHEAD,
        .flags = Sockaddr_flags_BCAST
    };
    Message_push(msg, &sa, Sockaddr_OVERHEAD, NULL);

    Iface_send(&ici->pub.addrIf, msg);
}

static void onPingResponse(enum SwitchPinger_Result result,
                           uint64_t label,
                           String* data,
                           uint32_t millisecondsLag,
                           uint32_t version,
                           void* onResponseContext)
{
    if (SwitchPinger_Result_OK != result) {
        return;
    }
    struct IFCPeer* ep = Identity_cast((struct IFCPeer*) onResponseContext);
    struct Context* ic = ifcontrollerForPeer(ep);

    struct Address addr;
    Bits_memset(&addr, 0, sizeof(struct Address));
    Bits_memcpyConst(addr.key, CryptoAuth_getHerPublicKey(ep->cryptoAuthIf), 32);
    addr.path = ep->switchLabel;
    Log_debug(ic->logger, "got switch pong from node with version [%d]", version);
    RouterModule_addNode(ic->routerModule, &addr, version);

    #ifdef Log_DEBUG
        // This will be false if it times out.
        //Assert_true(label == ep->switchLabel);
        uint8_t path[20];
        AddrTools_printPath(path, label);
        uint8_t sl[20];
        AddrTools_printPath(sl, ep->switchLabel);
        Log_debug(ic->logger, "Received [%s] from lazy endpoint [%s]  [%s]",
                  SwitchPinger_resultString(result)->bytes, path, sl);
    #endif
}

static void onGetPeers(Dict* msg,
                       struct Address* src,
                       struct Allocator* tmpAlloc,
                       struct MsgCore_Handler* handler)
{
    struct GetPeersResponder_pvt* gprp =
        Identity_check((struct GetPeersResponder_pvt*) handler->userData);
    Log_debug(gprp->log, "Received getPeers req from [%s]", Address_toString(src, tmpAlloc)->bytes);

    String* txid = Dict_getStringC(msg, "txid");
    if (!txid) {
        Log_debug(gprp->log, "getPeers missing txid");
        return;
    }

    String* nearLabelStr = Dict_getStringC(msg, "tar");
    uint64_t label;
    if (!nearLabelStr || nearLabelStr->len != 8) {
        Log_debug(gprp->log, "getPeers does not contain proper target");
        return;
    } else {
        uint64_t label_be;
        Bits_memcpy(&label_be, nearLabelStr->bytes, 8);
        label = Endian_bigEndianToHost64(label_be);
    }

    struct Address outAddrs[GETPEERS_RESPONSE_NODES] = { { .padding = 0 } };

static void onPingResponse(struct SwitchPinger_Response* resp, void* onResponseContext)
{
    if (SwitchPinger_Result_OK != resp->res) {
        return;
    }
    struct InterfaceController_Peer* ep =
        Identity_check((struct InterfaceController_Peer*) onResponseContext);
    struct InterfaceController_pvt* ic = ifcontrollerForPeer(ep);

    struct Address addr;
    Bits_memset(&addr, 0, sizeof(struct Address));
    Bits_memcpyConst(addr.key, CryptoAuth_getHerPublicKey(ep->cryptoAuthIf), 32);
    addr.path = ep->switchLabel;
    addr.protocolVersion = resp->version;

    #ifdef Log_DEBUG
        uint8_t addrStr[60];
        Address_print(addrStr, &addr);
        uint8_t key[56];
        Base32_encode(key, 56, CryptoAuth_getHerPublicKey(ep->cryptoAuthIf), 32);
    #endif

    if (!Version_isCompatible(Version_CURRENT_PROTOCOL, resp->version)) {
        Log_debug(ic->logger, "got switch pong from node [%s] with incompatible version [%d]",
                  key, resp->version);
    } else {
        Log_debug(ic->logger, "got switch pong from node [%s] with version [%d]",
                  key, resp->version);
    }

    if (!ep->timeOfLastPing) {
        // We've never heard from this machine before (or we've since forgotten about it)
        // This is here because we want the tests to function without the janitor present.
        // Other than that, it just makes a slightly more synchronous/guaranteed setup.
        Router_sendGetPeers(ic->router, &addr, 0, 0, ic->allocator);
    }

    struct Node_Link* link = Router_linkForPath(ic->router, resp->label);
    if (!link || !Node_getBestParent(link->child)) {
        RumorMill_addNode(ic->rumorMill, &addr);
    } else {
        Log_debug(ic->logger, "link exists");
    }

    ep->timeOfLastPing = Time_currentTimeMilliseconds(ic->eventBase);

    #ifdef Log_DEBUG
        // This will be false if it times out.
        //Assert_true(label == ep->switchLabel);
        uint8_t path[20];
        AddrTools_printPath(path, resp->label);
        uint8_t sl[20];
        AddrTools_printPath(sl, ep->switchLabel);
        Log_debug(ic->logger, "Received [%s] from lazy endpoint [%s]  [%s]",
                  SwitchPinger_resultString(resp->res)->bytes, path, sl);
    #endif
}

struct RouterModule_Promise* SearchRunner_search(uint8_t target[16],
                                                 int maxRequests,
                                                 int maxRequestsIfFound,
                                                 struct SearchRunner* searchRunner,
                                                 struct Allocator* allocator)
{
    struct SearchRunner_pvt* runner = Identity_check((struct SearchRunner_pvt*)searchRunner);

    if (runner->searches > runner->maxConcurrentSearches) {
        Log_debug(runner->logger, "Skipping search because there are already [%d] searches active",
                  runner->searches);
        return NULL;
    }

    if (maxRequests < 1) {
        maxRequests = SearchRunner_DEFAULT_MAX_REQUESTS;
    }
    if (maxRequestsIfFound < 1) {
        maxRequestsIfFound = SearchRunner_DEFAULT_MAX_REQUESTS_IF_FOUND;
    }

    struct Allocator* alloc = Allocator_child(allocator);

    struct Address targetAddr = { .path = 0 };
    Bits_memcpyConst(targetAddr.ip6.bytes, target, Address_SEARCH_TARGET_SIZE);

    struct NodeList* nodes =
        NodeStore_getClosestNodes(runner->nodeStore,
                                  &targetAddr,
                                  maxRequests,
                                  Version_CURRENT_PROTOCOL,
                                  alloc);

    if (nodes->size == 0) {
        Log_debug(runner->logger, "No nodes available for beginning search");
        Allocator_free(alloc);
        return NULL;
    }

    struct SearchStore_Search* sss = SearchStore_newSearch(target, runner->searchStore, alloc);

    for (int i = 0; i < (int)nodes->size; i++) {
        SearchStore_addNodeToSearch(&nodes->nodes[i]->address, sss);
    }

    struct SearchRunner_Search* search = Allocator_clone(alloc, (&(struct SearchRunner_Search) {
        .pub = {
            .alloc = alloc
        },
        .runner = runner,
        .search = sss,
        .maxRequests = maxRequests,
        .maxRequestsIfFound = maxRequestsIfFound
    }));

static uint8_t receiveMessage(struct Message* received, struct Interface* interface)
{
    struct CryptoAuth_Wrapper* wrapper =
        Identity_cast((struct CryptoAuth_Wrapper*) interface->receiverContext);

    union Headers_CryptoAuth* header = (union Headers_CryptoAuth*) received->bytes;

    if (received->length < (wrapper->authenticatePackets ? 20 : 4)) {
        Log_debug(wrapper->context->logger, "Dropped runt");
        return Error_UNDERSIZE_MESSAGE;
    }
    Assert_true(received->padding >= 12 || "need at least 12 bytes of padding in incoming message");
    #ifdef Log_DEBUG
        Assert_true(!((uintptr_t)received->bytes % 4) || !"alignment fault");
    #endif
    Message_shift(received, -4);

    uint32_t nonce = Endian_bigEndianToHost32(header->nonce);

    if (wrapper->nextNonce < 5) {
        if (nonce > 3 && nonce != UINT32_MAX && knowHerKey(wrapper)) {
            Log_debug(wrapper->context->logger,
                       "@%p Trying final handshake step, nonce=%u\n", (void*) wrapper, nonce);
            uint8_t secret[32];
            getSharedSecret(secret,
                            wrapper->secret,
                            wrapper->tempKey,
                            NULL,
                            wrapper->context->logger);

            // We'll optimistically advance the nextNonce value because decryptMessage()
            // passes the message on to the upper level and if this message causes a
            // response, we want the CA to be in ESTABLISHED state.
            // if the decryptMessage() call fails, we CryptoAuth_reset() it back.
            wrapper->nextNonce += 3;

            if (decryptMessage(wrapper, nonce, received, secret)) {
                Log_debug(wrapper->context->logger, "Final handshake step succeeded.\n");
                Bits_memcpyConst(wrapper->secret, secret, 32);
                return Error_NONE;
            }
            CryptoAuth_reset(&wrapper->externalInterface);
            Log_debug(wrapper->context->logger, "Final handshake step failed.\n");
        }
    } else if (nonce > 2 && decryptMessage(wrapper, nonce, received, wrapper->secret)) {
        // If decryptMessage returns false then we will try the packet as a handshake.
        return Error_NONE;
    } else {
        Log_debug(wrapper->context->logger, "Decryption failed, trying message as a handshake.\n");
    }
    Message_shift(received, 4);
    return decryptHandshake(wrapper, nonce, received, header);
}

static uint8_t sendMessage(struct Message* message, struct Interface* interface)
{
    struct CryptoAuth_Wrapper* wrapper =
        Identity_cast((struct CryptoAuth_Wrapper*) interface->senderContext);

    // If there has been no incoming traffic for a while, reset the connection to state 0.
    // This will prevent "connection in bad state" situations from lasting forever.
    uint64_t nowSecs = Time_currentTimeSeconds(wrapper->context->eventBase);

    if (nowSecs - wrapper->timeOfLastPacket > wrapper->context->pub.resetAfterInactivitySeconds) {
        Log_debug(wrapper->context->logger, "No traffic in [%d] seconds, resetting connection.",
                  (int) (nowSecs - wrapper->timeOfLastPacket));

        wrapper->timeOfLastPacket = nowSecs;
        CryptoAuth_reset(interface);
        return encryptHandshake(message, wrapper);
    }

    #ifdef Log_DEBUG
        Assert_true(!((uintptr_t)message->bytes % 4) || !"alignment fault");
    #endif

    // nextNonce 0: sending hello, we are initiating connection.
    // nextNonce 1: sending another hello, nothing received yet.
    // nextNonce 2: sending key, hello received.
    // nextNonce 3: sending key again, no data packet recieved yet.
    // nextNonce >3: handshake complete
    //
    // if it's a blind handshake, every message will be empty and nextNonce will remain
    // zero until the first message is received back.
    if (wrapper->nextNonce < 5) {
        if (wrapper->nextNonce < 4) {
            return encryptHandshake(message, wrapper);
        } else {
            Log_debug(wrapper->context->logger,
                       "@%p Doing final step to send message. nonce=4\n", (void*) wrapper);
            uint8_t secret[32];
            getSharedSecret(secret,
                            wrapper->secret,
                            wrapper->tempKey,
                            NULL,
                            wrapper->context->logger);
            Bits_memcpyConst(wrapper->secret, secret, 32);
        }
    }

    return encryptMessage(message, wrapper);
}