test: detect and reconnect when the server stops reading the bot socket

test/externalTest.js

@@ -9,7 +9,7 @@ const path = require('path')
 
 const { getPort } = require('./common/util')
 const trace = require('./common/trace')
-const { once } = require('../lib/promise_utils')
+const { once, onceWithCleanup, sleep } = require('../lib/promise_utils')
 
 // set this to false if you want to test without starting a server automatically
 const START_THE_SERVER = true
@@ -74,7 +74,9 @@ for (const supportedVersion of mineflayer.testedVersions) {
     })
     before(function (done) {
       this.timeout(1000 * 120)
+      let loginAttempts = 0
       function begin () {
+        loginAttempts++
         bot = mineflayer.createBot({
           username: 'flatbot',
           viewDistance: 'tiny',
@@ -91,6 +93,15 @@ for (const supportedVersion of mineflayer.testedVersions) {
         bot._client.on('error', err => trace.log('bot client error', { error: err?.message ?? String(err) }))
         bot._client.on('end', reason => trace.log('bot client ended', { reason }))
         bot.once('login', () => trace.log('bot logged in'))
+        // Console commands reach the bot even when the server has stopped
+        // reading its socket; the server echoing our skinParts (127) in our
+        // own entity_metadata is the only proof it is reading us.
+        let settingsAcked
+        bot._client.once('login', packet => {
+          settingsAcked = onceWithCleanup(bot._client, 'entity_metadata', {
+            checkCondition: p => p.entityId === packet.entityId && p.metadata.some(m => m.value === 127)
+          })
+        })
         bot.once('spawn', () => {
           console.log('bot spawned, opping...')
           trace.log('bot spawned, opping')
@@ -102,8 +113,18 @@ for (const supportedVersion of mineflayer.testedVersions) {
           }
           bot.once('messagestr', msg => {
             if (msg.includes('Made flatbot a server operator') || msg === '[Server: Opped flatbot]') {
-              trace.log('bot opped, setup done')
-              done()
+              Promise.race([settingsAcked, sleep(3000).then(() => { throw new Error('server is not reading the bot socket') })])
+                .then(() => {
+                  trace.log('bot opped, setup done')
+                  done()
+                }, err => {
+                  trace.log(err.message, { loginAttempts })
+                  console.log(err.message)
+                  if (loginAttempts >= 3) return done(err)
+                  wrap.writeServer('deop flatbot\n')
+                  bot.end()
+                  bot._client.once('end', begin)
+                })
             }
           })
         })

test/externalTests/plugins/testCommon.js

@@ -39,6 +39,7 @@ function inject (bot, wrap) {
   bot.test.setInventorySlot = setInventorySlot
   bot.test.placeBlock = placeBlock
   bot.test.runExample = runExample
+  bot.test.serverReads = serverReads
   bot.test.tellAndListen = tellAndListen
   bot.test.selfKill = selfKill
   bot.test.killEntity = killEntity
@@ -239,7 +240,22 @@ function inject (bot, wrap) {
     runningExample = null
   }
 
-  async function runExample (file, run) {
+  // The server echoes a bot's settings skinParts (127) in that bot's
+  // entity_metadata only once it has read the bot's socket. On <=1.20.1 a
+  // login race can leave a socket the server never reads again, and console
+  // commands still reach that bot, so this echo is the only proof of life.
+  async function serverReads (username, timeoutMs = 3000) {
+    const echoed = entity => entity?.username === username && Object.values(entity.metadata).includes(127)
+    // The echo usually lands before this gate runs, so check before listening.
+    if (echoed(bot.players[username]?.entity)) return
+    try {
+      await onceWithCleanup(bot, 'entityUpdate', { timeout: timeoutMs, checkCondition: echoed })
+    } catch {
+      throw Object.assign(new Error(`server is not reading ${username}'s socket`), { serverNotReading: true })
+    }
+  }
+
+  async function runExample (file, run, attempt = 1) {
     let childBotName
     const abort = new AbortController()
     runningExample = abort
@@ -258,6 +274,7 @@ function inject (bot, wrap) {
              bot.players[childBotName].entity.position.distanceTo(targetPos) > 5) {
         await sleep(100)
       }
+      await serverReads(childBotName)
       bot.chat('loaded')
     }
 
@@ -314,6 +331,11 @@ function inject (bot, wrap) {
       await Promise.race([Promise.all([detectChildJoin(), runExampleOnReady()]), childDied])
     } catch (err) {
       console.log(err)
+      // Relaunching under the same name makes the server kick the dead session.
+      if (err.serverNotReading && attempt < 3) {
+        await closeExample()
+        return runExample(file, run, attempt + 1)
+      }
       return closeExample(err)
     }
     return closeExample()

test/externalTests/spawnEvent.js

@@ -1,16 +1,32 @@
 const mineflayer = require('mineflayer')
-const { once } = require('../../lib/promise_utils')
+const { once, onceWithCleanup } = require('../../lib/promise_utils')
 
 module.exports = () => async (bot) => {
   // Test spawn event on login
-  const spawnBot = mineflayer.createBot({
-    username: 'spawnbot',
-    viewDistance: 'tiny',
-    port: bot.test.port,
-    host: '127.0.0.1',
-    version: bot.version
-  })
-  await once(spawnBot, 'spawn')
+  let spawnBot
+  for (let attempt = 1; ; attempt++) {
+    spawnBot = mineflayer.createBot({
+      username: 'spawnbot',
+      viewDistance: 'tiny',
+      port: bot.test.port,
+      host: '127.0.0.1',
+      version: bot.version
+    })
+    await once(spawnBot, 'spawn')
+    // spawnbot logs in at the world spawn, possibly out of flatbot's view, so
+    // its entity metadata is no proof of life; a chat line reaching flatbot is.
+    spawnBot.chat('spawnbot-alive')
+    try {
+      await onceWithCleanup(bot, 'chat', {
+        timeout: 3000,
+        checkCondition: (username, message) => username === spawnBot.username && message === 'spawnbot-alive'
+      })
+      break
+    } catch (err) {
+      if (attempt >= 3) throw new Error(`server is not reading ${spawnBot.username}'s socket`)
+      spawnBot.end()
+    }
+  }
   spawnBot.end()
 
   // Wait for the server to process the disconnection before killing the main bot