Logging improvements

This commit is contained in:
extremeheat 2021-06-18 15:23:12 -04:00
commit b546cda899
7 changed files with 37 additions and 33 deletions

View file

@ -35,8 +35,10 @@ class Client extends Connection {
this.startGameData = {}
this.clientRuntimeId = null
this.inLog = (...args) => debug('C ->', ...args)
this.outLog = (...args) => debug('C <-', ...args)
if (process.env.DEBUG.includes('minecraft-protocol')) {
this.inLog = (...args) => debug('C ->', ...args)
this.outLog = (...args) => debug('C <-', ...args)
}
}
connect () {

View file

@ -145,7 +145,6 @@ class MsAuthFlow {
const token = await this.mca.getAccessToken(publicKey, xsts)
// If we want to auth with a title ID, make sure there's a TitleID in the response
const body = JSON.parse(Buffer.from(token.chain[1].split('.')[1], 'base64').toString())
console.log(this.options.authTitle)
if (!body.extraData.titleId && this.options.authTitle) {
throw Error('missing titleId in response')
}

View file

@ -22,6 +22,7 @@ class Connection extends EventEmitter {
set status (val) {
debug('* new status', val)
this.emit('status', val)
this.#status = val
}
@ -35,7 +36,7 @@ class Connection extends EventEmitter {
startEncryption (iv) {
this.encryptionEnabled = true
this.inLog('Started encryption', this.sharedSecret, iv)
this.inLog?.('Started encryption', this.sharedSecret, iv)
this.decrypt = cipher.createDecryptor(this, iv)
this.encrypt = cipher.createEncryptor(this, iv)
}
@ -57,7 +58,7 @@ class Connection extends EventEmitter {
}
write (name, params) {
this.outLog('sending', name, params)
this.outLog?.(name, params)
if (name === 'start_game') this.updateItemPalette(params.itemstates)
const batch = new Framer()
const packet = this.serializer.createPacketBuffer({ name, params })
@ -71,7 +72,7 @@ class Connection extends EventEmitter {
}
queue (name, params) {
this.outLog('Q <- ', name, params)
this.outLog?.('Q <- ', name, params)
if (name === 'start_game') this.updateItemPalette(params.itemstates)
const packet = this.serializer.createPacketBuffer({ name, params })
if (name === 'level_chunk') {
@ -88,7 +89,6 @@ class Connection extends EventEmitter {
this.loop = setInterval(() => {
if (this.sendQ.length) {
const batch = new Framer()
this.outLog('<- Batch', this.sendIds)
batch.addEncodedPackets(this.sendQ)
this.sendQ = []
this.sendIds = []
@ -140,7 +140,6 @@ class Connection extends EventEmitter {
// These are callbacks called from encryption.js
onEncryptedPacket = (buf) => {
this.outLog('Enc buf', buf)
const packet = Buffer.concat([Buffer.from([0xfe]), buf]) // add header
this.sendMCPE(packet)
@ -160,7 +159,6 @@ class Connection extends EventEmitter {
this.decrypt(buffer.slice(1))
} else {
Framer.decode(buffer, packets => {
this.inLog('Reading ', packets.length, 'packets')
for (const packet of packets) {
this.readPacket(packet)
}

View file

@ -13,7 +13,6 @@ function KeyExchange (client, server, options) {
client.ecdhKeyPair = crypto.generateKeyPairSync('ec', { namedCurve: curve })
client.publicKeyDER = client.ecdhKeyPair.publicKey.export(der)
client.privateKeyPEM = client.ecdhKeyPair.privateKey.export(pem)
console.log(client.publicKeyPEM)
client.clientX509 = client.publicKeyDER.toString('base64')
function startClientboundEncryption (publicKey) {

View file

@ -46,7 +46,7 @@ class RelayPlayer extends Player {
const params = des.data.params
this.upInLog('->', name, params)
if (name === 'play_status' && params.status === 'login_success') return // We already sent this, this needs to be sent ASAP or client will disconnect
if (name === 'play_status' && params.status === 'login_success') return // Already sent this, this needs to be sent ASAP or client will disconnect
if (debugging) { // some packet encode/decode testing stuff
this.server.deserializer.verify(des, this.server.serializer)
@ -71,8 +71,8 @@ class RelayPlayer extends Player {
this.upOutLog('Flushing upstream queue')
for (const e of this.upQ) { // Send the queue
const des = this.server.deserializer.parsePacketBuffer(e)
if (des.data.name === 'client_cache_status') { // Currently broken, force off the chunk cache
// this.upstream.write('client_cache_status', { enabled: false })
if (des.data.name === 'client_cache_status') {
// Currently not working, force off the chunk cache
} else {
this.upstream.write(des.data.name, des.data.params)
}
@ -141,6 +141,12 @@ class Relay extends Server {
this.conLog = debug
}
// Called after a new player joins our proxy. We first create a new Client to connect to
// the remote server. Then we listen to soem events and proxy them over. The queue and
// flushing logic is more of an accessory to make sure the server or client recieves
// a packet, no matter what state it's in. For example, if the client wants to send a
// packet to the server but it's not connected, it will add to the queue and send as soon
// as a connection with the server is established.
openUpstreamConnection (ds, clientAddr) {
const client = new Client({
authTitle: this.options.authTitle,
@ -157,7 +163,7 @@ class Relay extends Server {
this.conLog('Connecting to', this.options.destination.host, this.options.destination.port)
client.outLog = ds.upOutLog
client.inLog = ds.upInLog
client.once('join', () => { // Intercept once handshaking done
client.once('join', () => {
// Tell the server to disable chunk cache for this connection as a client.
// Wait a bit for the server to ack and process, the continue with proxying
// otherwise the player can get stuck in an empty world.
@ -172,6 +178,7 @@ class Relay extends Server {
this.upstreams.set(clientAddr.hash, client)
}
// Close a connection to a remote backend server.
closeUpstreamConnection (clientAddr) {
const up = this.upstreams.get(clientAddr.hash)
if (!up) throw Error(`unable to close non-open connection ${clientAddr.hash}`)
@ -180,6 +187,8 @@ class Relay extends Server {
this.conLog('closed upstream connection', clientAddr)
}
// Called when a new player connects to our proxy server. Once the player has authenticted,
// we can open an upstream connection to the backend server.
onOpenConnection = (conn) => {
if (this.forceSingle && this.clientCount > 0) {
this.conLog('dropping connection as single client relay', conn)
@ -196,6 +205,7 @@ class Relay extends Server {
}
}
// When our server is closed, make sure to kick all of the connected clients and run emitters.
close (...a) {
for (const [, v] of this.upstreams) {
v.close(...a)

View file

@ -19,8 +19,6 @@ class Server extends EventEmitter {
/** @type {Object<string, Player>} */
this.clients = {}
this.clientCount = 0
this.inLog = (...args) => debug('S ->', ...args)
this.outLog = (...args) => debug('S <-', ...args)
this.conLog = debug
}
@ -52,7 +50,6 @@ class Server extends EventEmitter {
}
onEncapsulated = (buffer, address) => {
// this.inLog('encapsulated', address, buffer)
const client = this.clients[address]
if (!client) {
throw new Error(`packet from unknown inet addr: ${address}`)

View file

@ -1,12 +1,11 @@
const { ClientStatus, Connection } = require('./connection')
const fs = require('fs')
const Options = require('./options')
const debug = require('debug')('minecraft-protocol')
// const { serialize } = require('./datatypes/util')
const { serialize } = require('./datatypes/util')
const { KeyExchange } = require('./handshake/keyExchange')
const Login = require('./handshake/login')
const LoginVerify = require('./handshake/loginVerify')
const fs = require('fs')
const debug = require('debug')('minecraft-protocol')
class Player extends Connection {
constructor (server, connection) {
@ -23,8 +22,11 @@ class Player extends Connection {
this.startQueue()
this.status = ClientStatus.Authenticating
this.inLog = (...args) => debug('S ->', ...args)
this.outLog = (...args) => debug('S <-', ...args)
if (process.env.DEBUG.includes('minecraft-protocol')) {
this.inLog = (...args) => debug('S ->', ...args)
this.outLog = (...args) => debug('S <-', ...args)
}
}
getUserData () {
@ -33,7 +35,6 @@ class Player extends Connection {
onLogin (packet) {
const body = packet.data
// debug('Login body', body)
this.emit('loggingIn', body)
const clientVer = body.protocol_version
@ -60,7 +61,6 @@ class Player extends Connection {
this.disconnect('Server authentication error')
return
}
debug('Verified user pub key', key, userData)
this.emit('server.client_handshake', { key }) // internal so we start encryption
@ -101,7 +101,6 @@ class Player extends Connection {
// After sending Server to Client Handshake, this handles the client's
// Client to Server handshake response. This indicates successful encryption
onHandshake () {
// this.outLog('Sending login success!', this.status)
// https://wiki.vg/Bedrock_Protocol#Play_Status
this.write('play_status', { status: 'login_success' })
this.status = ClientStatus.Initializing
@ -111,7 +110,7 @@ class Player extends Connection {
close (reason) {
if (this.status !== ClientStatus.Disconnected) {
this.emit('close') // Emit close once
if (!reason) this.inLog('Client closed connection', this.connection?.address)
if (!reason) this.inLog?.('Client closed connection', this.connection?.address)
}
this.q = []
this.q2 = []
@ -126,12 +125,12 @@ class Player extends Connection {
var des = this.server.deserializer.parsePacketBuffer(packet) // eslint-disable-line
} catch (e) {
this.disconnect('Server error')
console.warn('Packet parsing failed! Writing dump to ./packetdump.bin')
fs.writeFile('packetdump.bin', packet)
fs.writeFile(`packetdump_${this.connection.address}_${Date.now()}.bin`, packet)
return
}
// this.inLog(des.data.name, serialize(des.data.params).slice(0, 200))
this.inLog?.(des.data.name, serialize(des.data.params).slice(0, 200))
switch (des.data.name) {
case 'login':
this.onLogin(des)
@ -142,13 +141,13 @@ class Player extends Connection {
break
case 'set_local_player_as_initialized':
this.status = ClientStatus.Initialized
this.inLog('Server client spawned')
this.inLog?.('Server client spawned')
// Emit the 'spawn' event
this.emit('spawn')
break
default:
if (this.status === ClientStatus.Disconnected || this.status === ClientStatus.Authenticating) {
this.inLog('ignoring', des.data.name)
this.inLog?.('ignoring', des.data.name)
return
}
}
@ -156,4 +155,4 @@ class Player extends Connection {
}
}
module.exports = { Player, ClientStatus }
module.exports = { Player }