Teaspeak-Server/server/src/client/voice/VoiceClient.cpp

#include <algorithm>
#include <memory>
#include <tomcrypt.h>
#include <arpa/inet.h>
#include <ThreadPool/Timer.h>
#include <misc/endianness.h>
#include <misc/memtracker.h>
#include <log/LogUtils.h>

#include "VoiceClient.h"
#include "src/VirtualServer.h"
#include "../../server/VoiceServer.h"

using namespace std;
using namespace std::chrono;
using namespace ts::server;
using namespace ts::protocol;

VoiceClient::VoiceClient(const std::shared_ptr<VoiceServer>& server, const sockaddr_storage* address) : SpeakingClient(server->server->sql, server->server), voice_server(server) {
    assert(address);
    memtrack::allocated<VoiceClient>(this);
    memcpy(&this->remote_address, address, sizeof(sockaddr_storage));

    debugMessage(this->server->getServerId(), " Creating VoiceClient instance at {}", (void*) this);
}

void VoiceClient::initialize() {
    this->event_handle_packet = make_shared<event::ProxiedEventEntry<VoiceClient>>(dynamic_pointer_cast<VoiceClient>(this->ref()), &VoiceClient::execute_handle_packet);

    this->properties()[property::CLIENT_TYPE] = ClientType::CLIENT_TEAMSPEAK;
    this->properties()[property::CLIENT_TYPE_EXACT] = ClientType::CLIENT_TEAMSPEAK;

    this->state = ConnectionState::INIT_HIGH;
    this->connection = new connection::VoiceClientConnection(this);
}

VoiceClient::~VoiceClient() {
    debugMessage(this->getServerId(), " Deleting VoiceClient instance at {}", (void*) this);

    this->state = ConnectionState::DISCONNECTED;
    delete this->connection;
    this->connection = nullptr;

    if(this->flushing_thread)
        logCritical(this->getServerId(), "Deleting a VoiceClient which should still be hold within the flush thread!");

    memtrack::freed<VoiceClient>(this);
}

void VoiceClient::sendCommand0(const std::string_view& cmd, bool low, std::unique_ptr<threads::Future<bool>> listener) {
    this->connection->send_command(cmd, low, std::move(listener));

#ifdef PKT_LOG_CMD
    logTrace(this->getServerId(), "{}[Command][Server -> Client] Sending command {}. Command low: {}. Full command: {}", CLIENT_STR_LOG_PREFIX, cmd.substr(0, cmd.find(' ')), low, cmd);
#endif
}
void VoiceClient::sendAcknowledge(uint16_t packetId, bool low) {
    char buffer[2];
    le2be16(packetId, buffer);

    auto pflags = PacketFlag::Unencrypted | PacketFlag::NewProtocol;
    this->connection->send_packet(low ? protocol::PacketType::ACK_LOW : protocol::PacketType::ACK, (PacketFlag::PacketFlag) pflags, buffer, 2);
#ifdef PKT_LOG_ACK
    logTrace(this->getServerId(), "{}[Acknowledge][Server -> Client] Sending acknowledge for {}", CLIENT_STR_LOG_PREFIX, packetId);
#endif
}

void VoiceClient::tick(const std::chrono::system_clock::time_point &time) {
    SpeakingClient::tick(time);
    {
        ALARM_TIMER(A1, "VoiceClient::tick", milliseconds(3));
        if(this->state == ConnectionState::CONNECTED) {
            if(this->lastPingRequest > this->lastPingResponse) { //Client is behind :)
                if(this->lastPingRequest - this->lastPingResponse > chrono::seconds(20)) {
                    debugMessage(this->getServerId(), "{} Got a ping timeout. (Last successful ping: {}ms ago. Last request {}ms. Last response {}ms). Trying to recover via command acknowledge.",
                                 CLIENT_STR_LOG_PREFIX,
                                 duration_cast<milliseconds>(this->lastPingRequest - this->lastPingResponse).count(),
                                 duration_cast<milliseconds>(time - this->lastPingRequest).count(),
                                 duration_cast<milliseconds>(time - this->lastPingResponse).count());

                    bool force;
                    this->request_connection_info(nullptr, force);
                    this->lastPingResponse = system_clock::now();
                    return;
                }
            }
            if(time - this->lastPingRequest >= chrono::milliseconds(1000)) {
                //TODO calculate the ping smooth
                if(this->lastPingResponse < this->lastPingRequest){
                    if(time - this->lastPingRequest >= chrono::milliseconds(1500)) { //Max
                        this->sendPingRequest();
                    }
                } else
                    this->sendPingRequest();
            }

            this->connection->packet_statistics().tick();
        } else if(this->state == ConnectionState::INIT_LOW || this->state == ConnectionState::INIT_HIGH) {
            if(this->last_packet_handshake.time_since_epoch().count() != 0) {
                if(time - this->last_packet_handshake > seconds(5)) {
                    debugMessage(this->getServerId(), "{} Got handshake timeout. {}. State: {} Time: {}", CLIENT_STR_LOG_PREFIX,
                                 this->getLoggingPeerIp() + ":" + to_string(this->getPeerPort()),
                                 this->state == ConnectionState::INIT_HIGH ? "INIT_HIGH" : "INIT_LOW",
                                 duration_cast<seconds>(time - this->last_packet_handshake).count()
                    );
                    this->close_connection(system_clock::now() + seconds(1));
                }
            }
        }
    }
}

bool VoiceClient::disconnect(const std::string &reason) {
    return this->disconnect(VREASON_SERVER_KICK, reason, this->server->serverRoot, true);
}

bool VoiceClient::disconnect(ts::ViewReasonId reason_id, const std::string &reason, const std::shared_ptr<ts::server::ConnectedClient>& invoker, bool notify_viewer) {
    /*
     * We don't have to lock the disconnect lock here, because we're not really unregistering the client.
     * Its only for the clients own flavour and everything which the client receives after will be ignored :)
     */

    ConnectionState old_state{};
    {
        std::lock_guard state_lock{this->state_lock};
        if(this->state == ConnectionState::DISCONNECTING || this->state == ConnectionState::DISCONNECTED)
            return false; //Already disconnecting/disconnected

        old_state = this->state;
        this->state = ConnectionState::DISCONNECTING;
    }

    if(old_state == ConnectionState::CONNECTED) {
        /* Client has been successflly initialized; Send normal disconnect. */

        Command cmd("notifyclientleftview");
        cmd["reasonmsg"] = reason;
        cmd["reasonid"] = reason_id;
        cmd["clid"] = this->getClientId();
        cmd["cfid"] = this->currentChannel ? this->currentChannel->channelId() : 0; //Failed when cid = 0????
        cmd["ctid"] = 0;

        if (invoker) {
            cmd["invokerid"] = invoker->getClientId();
            cmd["invokername"] = invoker->getDisplayName();
            cmd["invokeruid"] = invoker->getUid();
        }

        if(notify_viewer && this->server) {
            unique_lock channel_lock(this->server->channel_tree_lock);
            this->server->client_move(this->ref(), nullptr, invoker, reason, reason_id, false, channel_lock);
        } else {
            threads::MutexLock lock(this->command_lock);
            auto server_channel = dynamic_pointer_cast<ServerChannel>(this->currentChannel);
            if(server_channel)
                server_channel->unregister_client(_this.lock());
            this->currentChannel = nullptr;
        }

        auto listener = make_unique<threads::Future<bool>>();
        auto weak_self = this->_this;
        listener->waitAndGetLater([weak_self](bool* success) {
            if(weak_self.expired()) return;
            auto self = weak_self.lock();
            if(!self) return;

            if(!success || !*success) {
                debugMessage(self->getServerId(), "{} Failed to receive disconnect acknowledge!", CLIENT_STR_LOG_PREFIX_(self));
            } else
                debugMessage(self->getServerId(), "{} Received disconnect acknowledge!", CLIENT_STR_LOG_PREFIX_(self));

            self->close_connection(chrono::system_clock::time_point{}); /* we received the ack, we do not need to flush anything */
        }, system_clock::now() + seconds(5));
        this->sendCommand0(cmd.build(), false, std::move(listener));
    } else {
        //TODO: Extra case for INIT_HIGH?
        this->close_connection(chrono::system_clock::now() + chrono::seconds{5});
    }
    return true;
}

bool VoiceClient::close_connection(const system_clock::time_point &timeout) {
    auto self_lock  = dynamic_pointer_cast<VoiceClient>(_this.lock());
    assert(self_lock); //Should never happen!

    bool flush = timeout.time_since_epoch().count() > 0;
    {
        std::lock_guard state_lock{this->state_lock};

        if(this->state == ConnectionState::DISCONNECTED) return false;
        else if(this->state == ConnectionState::DISCONNECTING) {
            /* here is nothing to pay attention for */
        } else if(this->state == ConnectionState::DISCONNECTING_FLUSHING) {
            if(!flush) {
                this->state = ConnectionState::DISCONNECTED;
                return true; /* the flush thread will execute the final disconnect */
            } else {
                //TODO: May update the flush timeout if its less then the other one?
                return true;
            }
        }
        this->state = flush ? ConnectionState::DISCONNECTING_FLUSHING : ConnectionState::DISCONNECTED;
    }

    debugMessage(this->getServerId(), "{} Closing voice client connection. (Flush: {})", CLIENT_STR_LOG_PREFIX, flush);
    //TODO: Move this out into a thread pool?
    this->flushing_thread = std::make_shared<threads::Thread>(THREAD_SAVE_OPERATIONS | THREAD_EXECUTE_LATER, [this, self_lock, timeout, flush]{
        {
            /* Await that all commands have been processed. It does not make sense to unregister the client while command handling. */
            std::lock_guard cmd_lock{this->command_lock};
        }

        if(flush) {
            debugMessage(this->getServerId(), "{} Awaiting write prepare, write and acknowledge queue flushed", CLIENT_STR_LOG_PREFIX);
            while(this->state == DISCONNECTING_FLUSHING) {
                if(system_clock::now() > timeout){
                    auto write_queue_flushed = this->connection->wait_empty_write_and_prepare_queue(timeout);
                    auto acknowledge_received = connection->acknowledge_handler.awaiting_acknowledge() == 0;

                    if(write_queue_flushed && acknowledge_received)
                        break;

                    debugMessage(this->getServerId(), "{} Failed to flush pending messages. Acknowledges pending: {} Buffers pending: {}", CLIENT_STR_LOG_PREFIX, acknowledge_received, write_queue_flushed);
                    break;
                }
                if(!this->connection->wait_empty_write_and_prepare_queue(timeout))
                    continue;

                if(connection->acknowledge_handler.awaiting_acknowledge() > 0) {
                    usleep(5000);
                    continue;
                }
                debugMessage(this->getServerId(), "{} Write and acknowledge queue are flushed", CLIENT_STR_LOG_PREFIX);
                break;
            }
        }

        if(this->state > DISCONNECTING) /* it could happen that the client "reconnects" while flushing this shit */
            this->finalDisconnect();
    });
    flushing_thread->name("Flush thread VC").execute();
    return true;
}

void VoiceClient::finalDisconnect() {
    auto ownLock = dynamic_pointer_cast<VoiceClient>(_this.lock());
    assert(ownLock);

    lock_guard disconnect_lock_final(this->finalDisconnectLock);
    if(this->final_disconnected) {
        logError(this->getServerId(), "Tried to final disconnect {}/{} twice", this->getLoggingPeerIp() + ":" + to_string(this->getPeerPort()), this->getDisplayName());
        return;
    }
    this->final_disconnected = true;
    this->state = ConnectionState::DISCONNECTED;

    threads::MutexLock command_lock(this->command_lock); //We should not progress any commands while disconnecting
    //Unload manager cache
    this->processLeave();
    {
        if(this->flushing_thread) this->flushing_thread->detach(); //The thread itself should be already done or executing this method
        this->flushing_thread.reset();
    }
    if(this->voice_server) this->voice_server->unregisterConnection(ownLock);
}

void VoiceClient::execute_handle_packet(const std::chrono::system_clock::time_point &time) {
    this->connection->execute_handle_command_packets(time);
}

void VoiceClient::send_voice_packet(const pipes::buffer_view &voice_buffer, const SpeakingClient::VoicePacketFlags &flags) {
    PacketFlag::PacketFlags packet_flags{PacketFlag::None};
    packet_flags |= flags.encrypted ? 0U : PacketFlag::Unencrypted;
    packet_flags |= flags.head ? PacketFlag::Compressed : 0U;
    packet_flags |= flags.fragmented ? PacketFlag::Fragmented : 0U;
    packet_flags |= flags.new_protocol ? PacketFlag::NewProtocol : 0U;

    this->connection->send_packet(PacketType::VOICE, packet_flags, voice_buffer.data_ptr<void>(), voice_buffer.length());
}

void VoiceClient::send_voice_whisper_packet(const pipes::buffer_view &voice_buffer, const SpeakingClient::VoicePacketFlags &flags) {
    PacketFlag::PacketFlags packet_flags{PacketFlag::None};
    packet_flags |= flags.encrypted ? 0U : PacketFlag::Unencrypted;
    packet_flags |= flags.head ? PacketFlag::Compressed : 0U;
    packet_flags |= flags.fragmented ? PacketFlag::Fragmented : 0U;
    packet_flags |= flags.new_protocol ? PacketFlag::NewProtocol : 0U;

    this->connection->send_packet(PacketType::VOICE_WHISPER, packet_flags, voice_buffer.data_ptr<void>(), voice_buffer.length());
}

float VoiceClient::current_ping_deviation() {
    return this->connection->getAcknowledgeManager().current_rttvar();
}

float VoiceClient::current_packet_loss() const {
    return this->connection->packet_statistics().current_packet_loss();
}