2019-07-17 19:37:18 +02:00
# include <algorithm>
# include <log/LogUtils.h>
# include "../../server/VoiceServer.h"
# include <misc/memtracker.h>
# include <protocol/Packet.h>
# include <ThreadPool/Timer.h>
# include "VoiceClientConnection.h"
# include "VoiceClient.h"
//#define LOG_AUTO_ACK_AUTORESPONSE
//#define FUZZING_TESTING_INCOMMING
//#define FUZZING_TESTING_OUTGOING
2020-01-27 02:21:39 +01:00
//#define FIZZING_TESTING_DISABLE_HANDSHAKE
# define FUZZING_TESTING_DROP 8
2019-07-17 19:37:18 +02:00
# define FUZZING_TESTING_DROP_MAX 10
//#define CONNECTION_NO_STATISTICS
# define QLZ_COMPRESSION_LEVEL 1
# include "qlz/QuickLZ.h"
using namespace std ;
using namespace std : : chrono ;
using namespace ts ;
using namespace ts : : connection ;
using namespace ts : : protocol ;
using namespace ts : : server ;
2020-07-29 19:05:38 +02:00
VoiceClientConnection : : VoiceClientConnection ( VoiceClient * client )
: client { client } , crypt_handler { } , packet_decoder_ { & this - > crypt_handler } , packet_encoder_ { & this - > crypt_handler , & this - > packet_statistics_ } {
2020-01-24 02:57:58 +01:00
memtrack : : allocated < VoiceClientConnection > ( this ) ;
2019-07-17 19:37:18 +02:00
2020-07-29 19:05:38 +02:00
this - > packet_decoder_ . callback_argument = this ;
this - > packet_decoder_ . callback_decoded_packet = VoiceClientConnection : : callback_packet_decoded ;
this - > packet_decoder_ . callback_decoded_command = VoiceClientConnection : : callback_command_decoded ;
this - > packet_decoder_ . callback_send_acknowledge = VoiceClientConnection : : callback_send_acknowledge ;
this - > packet_encoder_ . callback_data = this ;
this - > packet_encoder_ . callback_request_write = VoiceClientConnection : : callback_request_write ;
this - > packet_encoder_ . callback_crypt_error = VoiceClientConnection : : callback_encode_crypt_error ;
this - > packet_encoder_ . callback_resend_failed = VoiceClientConnection : : callback_resend_failed ;
this - > packet_encoder_ . callback_resend_stats = VoiceClientConnection : : callback_resend_statistics ;
this - > packet_encoder_ . callback_connection_stats = VoiceClientConnection : : callback_outgoing_connection_statistics ;
2020-04-24 22:04:07 +02:00
2020-01-24 02:57:58 +01:00
debugMessage ( client - > getServer ( ) - > getServerId ( ) , " Allocated new voice client connection at {} " , ( void * ) this ) ;
2019-07-17 19:37:18 +02:00
}
VoiceClientConnection : : ~ VoiceClientConnection ( ) {
2020-04-24 22:04:07 +02:00
this - > reset ( ) ;
2020-01-24 02:57:58 +01:00
this - > client = nullptr ;
memtrack : : freed < VoiceClientConnection > ( this ) ;
2019-07-17 19:37:18 +02:00
}
void VoiceClientConnection : : triggerWrite ( ) {
2020-01-24 02:57:58 +01:00
if ( this - > client - > voice_server )
this - > client - > voice_server - > triggerWrite ( dynamic_pointer_cast < VoiceClient > ( this - > client - > _this . lock ( ) ) ) ;
2019-07-17 19:37:18 +02:00
}
# ifdef CLIENT_LOG_PREFIX
2020-07-29 19:05:38 +02:00
# undef CLIENT_LOG_PREFIX
2019-07-17 19:37:18 +02:00
# endif
# define CLIENT_LOG_PREFIX "[" << this->client->getPeerIp() << ":" << this->client->getPeerPort() << " | " << this->client->getDisplayName() << "]"
//Message handle methods
2020-01-27 02:21:39 +01:00
void VoiceClientConnection : : handle_incoming_datagram ( const pipes : : buffer_view & buffer ) {
2020-02-15 14:03:46 +01:00
ClientPacketParser packet_parser { buffer } ;
2020-07-29 19:05:38 +02:00
if ( ! packet_parser . valid ( ) )
2020-01-24 02:57:58 +01:00
return ;
2020-04-08 13:01:41 +02:00
# ifndef CONNECTION_NO_STATISTICS
if ( this - > client ) {
auto stats = this - > client - > connectionStatistics ;
stats - > logIncomingPacket ( stats : : ConnectionStatistics : : category : : from_type ( packet_parser . type ( ) ) , buffer . length ( ) + 96 ) ; /* 96 for the UDP packet overhead */
}
this - > packet_statistics ( ) . received_packet ( ( protocol : : PacketType ) packet_parser . type ( ) , packet_parser . full_packet_id ( ) ) ;
# endif
2020-07-29 19:05:38 +02:00
std : : string error { } ;
auto result = this - > packet_decoder_ . process_incoming_data ( packet_parser , error ) ;
using PacketProcessResult = server : : server : : udp : : PacketProcessResult ;
switch ( result ) {
case PacketProcessResult : : SUCCESS :
case PacketProcessResult : : FUZZ_DROPPED : /* maybe some kind of log? */
case PacketProcessResult : : DECRYPT_FAILED : /* Silently drop this packet */
case PacketProcessResult : : DUPLICATED_PACKET : /* no action needed, acknowledge should be send already */
break ;
case PacketProcessResult : : DECRYPT_KEY_GEN_FAILED :
/* no action needed, acknowledge should be send */
logCritical ( this - > client - > getServerId ( ) , " {} Failed to generate decrypt key. Dropping packet. " , CLIENT_STR_LOG_PREFIX_ ( this - > client ) ) ;
break ;
case PacketProcessResult : : BUFFER_OVERFLOW :
case PacketProcessResult : : BUFFER_UNDERFLOW :
debugMessage ( this - > client - > getServerId ( ) , " {} Dropping command packet because command assembly buffer has an {}: {} " ,
CLIENT_STR_LOG_PREFIX_ ( this - > client ) ,
result = = PacketProcessResult : : BUFFER_UNDERFLOW ? " underflow " : " overflow " ,
error
) ;
break ;
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
case PacketProcessResult : : UNKNOWN_ERROR :
logCritical ( this - > client - > getServerId ( ) , " {} Having an unknown error while processing a incoming packet: {} " ,
CLIENT_STR_LOG_PREFIX_ ( this - > client ) ,
error
) ;
goto disconnect_client ;
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
case PacketProcessResult : : COMMAND_BUFFER_OVERFLOW :
debugMessage ( this - > client - > getServerId ( ) , " {} Having a command buffer overflow. This might cause the client to drop. " , CLIENT_STR_LOG_PREFIX_ ( this - > client ) ) ;
break ;
2020-01-24 02:57:58 +01:00
2020-07-29 19:05:38 +02:00
case PacketProcessResult : : COMMAND_DECOMPRESS_FAILED :
logWarning ( this - > client - > getServerId ( ) , " {} Failed to decompress a command packet. Dropping command. " , CLIENT_STR_LOG_PREFIX_ ( this - > client ) ) ;
break ;
2020-01-24 02:57:58 +01:00
2020-07-29 19:05:38 +02:00
case PacketProcessResult : : COMMAND_TOO_LARGE :
logWarning ( this - > client - > getServerId ( ) , " {} Received a too large command. Dropping client. " , CLIENT_STR_LOG_PREFIX_ ( this - > client ) ) ;
goto disconnect_client ;
case PacketProcessResult : : COMMAND_SEQUENCE_LENGTH_TOO_LONG :
logWarning ( this - > client - > getServerId ( ) , " {} Received a too long command sequence. Dropping client. " , CLIENT_STR_LOG_PREFIX_ ( this - > client ) ) ;
goto disconnect_client ;
default :
assert ( false ) ;
break ;
2020-01-24 02:57:58 +01:00
}
2020-07-29 19:05:38 +02:00
return ;
2020-01-24 02:57:58 +01:00
2020-07-29 19:05:38 +02:00
disconnect_client : ;
/* FIXME: Disconnect the client */
}
2020-01-24 02:57:58 +01:00
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : callback_send_acknowledge ( void * ptr_this , uint16_t packet_id , bool command_low ) {
/* FIXME: Move this to the connection! */
reinterpret_cast < VoiceClientConnection * > ( ptr_this ) - > client - > sendAcknowledge ( packet_id , command_low ) ;
}
2020-01-27 02:21:39 +01:00
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : callback_packet_decoded ( void * ptr_this , const ts : : protocol : : ClientPacketParser & packet ) {
auto connection = reinterpret_cast < VoiceClientConnection * > ( ptr_this ) ;
switch ( packet . type ( ) ) {
case protocol : : VOICE :
connection - > client - > handlePacketVoice ( packet ) ;
break ;
case protocol : : VOICE_WHISPER :
connection - > client - > handlePacketVoiceWhisper ( packet ) ;
break ;
case protocol : : ACK :
case protocol : : ACK_LOW :
connection - > client - > handlePacketAck ( packet ) ;
break ;
case protocol : : PING :
case protocol : : PONG :
connection - > client - > handlePacketPing ( packet ) ;
break ;
default :
assert ( false ) ;
logError ( connection - > client - > getServerId ( ) , " {} Received hand decoded packet, but we've no method to handle it. Dropping packet. " , CLIENT_STR_LOG_PREFIX_ ( connection - > client ) ) ;
break ;
}
}
2020-01-27 02:21:39 +01:00
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : callback_command_decoded ( void * ptr_this , ts : : server : : server : : udp : : ReassembledCommand * & command ) {
auto connection = reinterpret_cast < VoiceClientConnection * > ( ptr_this ) ;
2020-01-27 02:21:39 +01:00
2020-07-29 19:05:38 +02:00
/* we're exchanging the command so we're taking the ownership */
connection - > enqueue_command_execution ( std : : exchange ( command , nullptr ) ) ;
}
2020-01-24 02:57:58 +01:00
2020-07-29 19:05:38 +02:00
bool VoiceClientConnection : : verify_encryption ( const pipes : : buffer_view & buffer /* incl. mac etc */ ) {
return this - > packet_decoder_ . verify_encryption ( buffer ) ;
}
2019-07-17 19:37:18 +02:00
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : enqueue_command_execution ( ReassembledCommand * command ) {
assert ( ! command - > next_command ) ;
2020-01-24 02:57:58 +01:00
2020-07-29 19:05:38 +02:00
bool command_handling_scheduled { false } ;
{
std : : lock_guard pc_lock { this - > pending_commands_lock } ;
* this - > pending_commands_tail = command ;
this - > pending_commands_tail = & command - > next_command ;
2020-01-27 02:21:39 +01:00
2020-07-29 19:05:38 +02:00
command_handling_scheduled = std : : exchange ( this - > has_command_handling_scheduled , true ) ;
}
2020-01-24 02:57:58 +01:00
2020-07-29 19:05:38 +02:00
if ( ! command_handling_scheduled ) {
2020-01-27 02:21:39 +01:00
auto voice_server = this - > client - > voice_server ;
if ( voice_server )
voice_server - > schedule_command_handling ( this - > client ) ;
}
2019-07-17 19:37:18 +02:00
}
2020-01-27 02:21:39 +01:00
void VoiceClientConnection : : execute_handle_command_packets ( const std : : chrono : : system_clock : : time_point & /* scheduled */ ) {
2020-02-01 14:32:16 +01:00
if ( this - > client - > state > = ConnectionState : : DISCONNECTING | | ! this - > client - > getServer ( ) )
2020-01-24 02:57:58 +01:00
return ;
2020-07-29 19:05:38 +02:00
std : : unique_ptr < ReassembledCommand , void ( * ) ( ReassembledCommand * ) > pending_command { nullptr , ReassembledCommand : : free } ;
while ( true ) {
{
std : : lock_guard pc_lock { this - > pending_commands_lock } ;
pending_command . reset ( this - > pending_commands_head ) ;
if ( ! pending_command ) {
this - > has_command_handling_scheduled = false ;
return ;
} else if ( pending_command - > next_command ) {
this - > pending_commands_head = pending_command - > next_command ;
} else {
this - > pending_commands_head = nullptr ;
this - > pending_commands_tail = & this - > pending_commands_head ;
}
}
2020-01-24 02:57:58 +01:00
auto startTime = system_clock : : now ( ) ;
try {
2020-07-29 19:05:38 +02:00
this - > client - > handlePacketCommand ( pipes : : buffer_view { pending_command - > command ( ) , pending_command - > length ( ) } ) ;
2020-01-24 02:57:58 +01:00
} catch ( std : : exception & ex ) {
logCritical ( this - > client - > getServerId ( ) , " {} Exception reached root tree! {} " , CLIENT_STR_LOG_PREFIX_ ( this - > client ) , ex . what ( ) ) ;
}
auto end = system_clock : : now ( ) ;
if ( end - startTime > milliseconds ( 10 ) ) {
2020-01-27 02:21:39 +01:00
logError ( this - > client - > getServerId ( ) ,
" {} Handling of command packet needs more than 10ms ({}ms) " ,
CLIENT_STR_LOG_PREFIX_ ( this - > client ) ,
duration_cast < milliseconds > ( end - startTime ) . count ( )
) ;
2020-01-24 02:57:58 +01:00
}
2020-04-08 13:01:41 +02:00
2020-07-29 19:05:38 +02:00
break ; /* Maybe handle more than one command? Maybe some kind of time limit? */
2020-01-24 02:57:58 +01:00
}
2019-07-17 19:37:18 +02:00
2020-07-29 19:05:38 +02:00
auto voice_server = this - > client - > voice_server ;
if ( voice_server )
voice_server - > schedule_command_handling ( this - > client ) ;
2019-07-17 19:37:18 +02:00
}
bool VoiceClientConnection : : wait_empty_write_and_prepare_queue ( chrono : : time_point < chrono : : system_clock > until ) {
2020-07-29 19:05:38 +02:00
return this - > packet_encoder_ . wait_empty_write_and_prepare_queue ( until ) ;
2019-07-17 19:37:18 +02:00
}
void VoiceClientConnection : : reset ( ) {
2020-07-29 19:05:38 +02:00
this - > crypt_handler . reset ( ) ;
2020-04-24 22:04:07 +02:00
{
2020-07-29 19:05:38 +02:00
std : : unique_lock pc_lock { this - > pending_commands_lock } ;
auto head = std : : exchange ( this - > pending_commands_head , nullptr ) ;
this - > pending_commands_tail = & this - > pending_commands_head ;
pc_lock . unlock ( ) ;
2020-04-24 22:04:07 +02:00
while ( head ) {
2020-07-29 19:05:38 +02:00
auto cmd = head - > next_command ;
ReassembledCommand : : free ( head ) ;
head = cmd ;
2020-01-24 02:57:58 +01:00
}
}
2020-07-29 19:05:38 +02:00
this - > packet_decoder_ . reset ( ) ;
this - > packet_encoder_ . reset ( ) ;
2019-07-17 19:37:18 +02:00
}
2020-01-27 02:21:39 +01:00
void VoiceClientConnection : : force_insert_command ( const pipes : : buffer_view & buffer ) {
2020-07-29 19:05:38 +02:00
auto command = ReassembledCommand : : allocate ( buffer . length ( ) ) ;
memcpy ( command - > command ( ) , buffer . data_ptr ( ) , command - > length ( ) ) ;
this - > enqueue_command_execution ( command ) ;
2020-04-24 22:04:07 +02:00
}
void VoiceClientConnection : : send_packet ( protocol : : OutgoingServerPacket * packet ) {
2020-07-29 19:05:38 +02:00
this - > packet_encoder_ . send_packet ( packet ) ;
2020-04-24 22:04:07 +02:00
auto statistics = this - > client ? this - > client - > connectionStatistics : nullptr ;
if ( statistics ) {
auto category = stats : : ConnectionStatistics : : category : : from_type ( packet - > packet_type ( ) ) ;
statistics - > logOutgoingPacket ( category , packet - > packet_length ( ) + 96 ) ; /* 96 for the UDP packet overhead */
}
}
void VoiceClientConnection : : send_packet ( protocol : : PacketType type , protocol : : PacketFlag : : PacketFlags flag , const void * payload , size_t payload_size ) {
auto packet = protocol : : allocate_outgoing_packet ( payload_size ) ;
packet - > type_and_flags = ( uint8_t ) type | ( uint8_t ) flag ;
memcpy ( packet - > payload , payload , payload_size ) ;
this - > send_packet ( packet ) ;
}
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : send_command ( const std : : string_view & cmd , bool b , std : : unique_ptr < threads : : Future < bool > > cb ) {
this - > packet_encoder_ . send_command ( cmd , b , std : : move ( cb ) ) ;
}
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : callback_encode_crypt_error ( void * ptr_this ,
const PacketEncoder : : CryptError & error ,
const std : : string & detail ) {
auto connection = reinterpret_cast < VoiceClientConnection * > ( ptr_this ) ;
switch ( error ) {
case PacketEncoder : : CryptError : : ENCRYPT_FAILED :
logError ( connection - > client - > getServerId ( ) , " {} Failed to encrypt packet. Error: {} " , CLIENT_STR_LOG_PREFIX_ ( connection - > client ) , detail ) ;
break ;
case PacketEncoder : : CryptError : : KEY_GENERATION_FAILED :
logError ( connection - > client - > getServerId ( ) , " {} Failed to generate crypt key/nonce for sending a packet. This should never happen! Dropping packet. " , CLIENT_STR_LOG_PREFIX_ ( connection - > client ) ) ;
break ;
default :
assert ( false ) ;
2020-04-24 22:04:07 +02:00
return ;
}
2020-07-29 19:05:38 +02:00
}
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : callback_request_write ( void * ptr_this ) {
auto connection = reinterpret_cast < VoiceClientConnection * > ( ptr_this ) ;
connection - > triggerWrite ( ) ;
}
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : callback_resend_failed ( void * ptr_this , const shared_ptr < AcknowledgeManager : : Entry > & entry ) {
auto connection = reinterpret_cast < VoiceClientConnection * > ( ptr_this ) ;
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
debugMessage ( connection - > client - > getServerId ( ) , " {} Failed to execute packet resend of packet {}. Dropping connection. " , CLIENT_STR_LOG_PREFIX_ ( connection - > client ) , entry - > packet_full_id ) ;
2020-04-25 11:26:00 +02:00
2020-07-29 19:05:38 +02:00
if ( connection - > client - > state = = ConnectionState : : CONNECTED ) {
connection - > client - > disconnect ( ViewReasonId : : VREASON_TIMEOUT , config : : messages : : timeout : : packet_resend_failed , nullptr , true ) ;
2020-04-24 22:04:07 +02:00
} else {
2020-07-29 19:05:38 +02:00
connection - > client - > close_connection ( system_clock : : now ( ) + seconds ( 1 ) ) ;
2020-04-24 22:04:07 +02:00
}
2020-07-29 19:05:38 +02:00
}
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : callback_resend_statistics ( void * ptr_this , size_t send_count ) {
auto connection = reinterpret_cast < VoiceClientConnection * > ( ptr_this ) ;
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
logTrace ( connection - > client - > getServerId ( ) , " {} Resending {} packets. " , CLIENT_STR_LOG_PREFIX_ ( connection - > client ) , send_count ) ;
}
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
void VoiceClientConnection : : callback_outgoing_connection_statistics ( void * ptr_this ,
ts : : stats : : ConnectionStatistics : : category : : value category ,
size_t send_count ) {
auto connection = reinterpret_cast < VoiceClientConnection * > ( ptr_this ) ;
auto statistics = connection - > client - > connectionStatistics ;
if ( ! statistics ) return ;
2020-04-24 22:04:07 +02:00
2020-07-29 19:05:38 +02:00
statistics - > logOutgoingPacket ( category , send_count ) ;
2020-01-27 02:21:39 +01:00
}