Remove debug leftovers from a test. (#314)

* Remove debug leftovers from a test.

This is really terrible and has meant whenever anyone has run `yarn test:integration` they have only been running this test.
💀💀💀
https://www.youtube.com/watch?v=jmX-tzSOFE0

* Set a default timeout for integration tests that is 5 minutes long.

Seriously, I don't think there is much to gain by making people guess
a reasnoble time for a test to complete in all the time, especially
with how much Synapse changes in response time and all of the machines
involved in running these tests.

* Warn when giving up on being throttled

* For some reason it takes longer for events to appear in /state

no i am not going to track down why yet.

* Rate limiting got a lot more aggresive.

matrix-org/synapse#13018

Rate limiting in Synapse used to reset the burst count and remove
the backoff when you were spamming continuously, now it doesn't.
Ideally we'd rewrite the rate limiting logic to back off for longer
than suggested so we could get burst again, but for now
lets just unblock CI by reducing the number of events we send in these
tests.

Author: Gnuxie

package.json

@@ -13,7 +13,7 @@
     "lint": "tslint --project ./tsconfig.json -t stylish",
     "start:dev": "yarn build && node --async-stack-traces lib/index.js",
     "test": "ts-mocha --project ./tsconfig.json test/commands/**/*.ts",
-    "test:integration": "NODE_ENV=harness ts-mocha --async-stack-traces --require test/integration/fixtures.ts --project ./tsconfig.json \"test/integration/**/*Test.ts\"",
+    "test:integration": "NODE_ENV=harness ts-mocha --async-stack-traces --require test/integration/fixtures.ts --timeout 300000 --project ./tsconfig.json \"test/integration/**/*Test.ts\"",
     "test:manual": "NODE_ENV=harness ts-node test/integration/manualLaunchScript.ts",
     "version": "sed -i '/# version automated/s/[0-9][0-9]*\\.[0-9][0-9]*\\.[0-9][0-9]*/'$npm_package_version'/' synapse_antispam/setup.py && git add synapse_antispam/setup.py && cat synapse_antispam/setup.py"
   },

src/utils.ts

@@ -386,6 +386,9 @@ function patchMatrixClientForRetry() {
                                 // We need to retry.
                                 reject(err);
                             } else {
+                                if (attempt >= MAX_REQUEST_ATTEMPTS) {
+                                    LogService.warn('Mjolnir.client', `Retried request ${params.method} ${params.uri} ${attempt} times, giving up.`);
+                                }
                                 // No need-to-retry error? Lucky us!
                                 // Note that this may very well be an error, just not
                                 // one we need to retry.

test/integration/banListTest.ts

@@ -231,7 +231,6 @@ describe('Test: We will not be able to ban ourselves via ACL.', function () {
 
 describe('Test: ACL updates will batch when rules are added in succession.', function () {
     it('Will batch ACL updates if we spam rules into a BanList', async function () {
-        this.timeout(180000)
         const mjolnir = config.RUNTIME.client!
         const serverName: string = new UserID(await mjolnir.getUserId()).domain
         const moderator = await newTestUser({ name: { contains: "moderator" }});
@@ -268,6 +267,8 @@ describe('Test: ACL updates will batch when rules are added in succession.', fun
             // Give them a bit of a spread over time.
             await new Promise(resolve => setTimeout(resolve, 5));
         }
+        // give the events a chance to appear in the response to `/state`, since this is a problem.
+        await new Promise(resolve => setTimeout(resolve, 2000));
 
         // We do this because it should force us to wait until all the ACL events have been applied.
         // Even if that does mean the last few events will not go through batching...
@@ -364,9 +365,9 @@ describe('Test: unbaning entities via the BanList.', function () {
     })
 })
 
-describe.only('Test: should apply bans to the most recently active rooms first', function () {
+describe('Test: should apply bans to the most recently active rooms first', function () {
     it('Applies bans to the most recently active rooms first', async function () {
-        this.timeout(6000000000)
+        this.timeout(180000)
         const mjolnir = config.RUNTIME.client!
         const serverName: string = new UserID(await mjolnir.getUserId()).domain
         const moderator = await newTestUser({ name: { contains: "moderator" }});

test/integration/throttleTest.ts

@@ -5,17 +5,16 @@ import { getFirstReaction } from "./commands/commandUtils";
 
 describe("Test: throttled users can function with Mjolnir.", function () {
     it('throttled users survive being throttled by synapse', async function() {
-        this.timeout(60000);
         let throttledUser = await newTestUser({ name: { contains: "throttled" }, isThrottled: true });
         let throttledUserId = await throttledUser.getUserId();
         let targetRoom = await throttledUser.createRoom();
         // send enough messages to hit the rate limit.
-        await Promise.all([...Array(150).keys()].map((i) => throttledUser.sendMessage(targetRoom, {msgtype: 'm.text.', body: `Message #${i}`})));
+        await Promise.all([...Array(25).keys()].map((i) => throttledUser.sendMessage(targetRoom, {msgtype: 'm.text.', body: `Message #${i}`})));
         let messageCount = 0;
-        await getMessagesByUserIn(throttledUser, throttledUserId, targetRoom, 150, (events) => {
+        await getMessagesByUserIn(throttledUser, throttledUserId, targetRoom, 25, (events) => {
             messageCount += events.length;
         });
-        assert.equal(messageCount, 150, "There should have been 150 messages in this room");
+        assert.equal(messageCount, 25, "There should have been 25 messages in this room");
     })
 })
 
@@ -31,7 +30,6 @@ describe("Test: Mjolnir can still sync and respond to commands while throttled",
     })
 
     it('Can still perform and respond to a redaction command', async function () {
-        this.timeout(60000);
         // Create a few users and a room.
         let badUser = await newTestUser({ name: { contains: "spammer-needs-redacting" } });
         let badUserId = await badUser.getUserId();
@@ -45,12 +43,12 @@ describe("Test: Mjolnir can still sync and respond to commands while throttled",
         await badUser.joinRoom(targetRoom);
 
         // Give Mjolnir some work to do and some messages to sync through.
-        await Promise.all([...Array(100).keys()].map((i) => moderator.sendMessage(this.mjolnir.managementRoomId, {msgtype: 'm.text.', body: `Irrelevant Message #${i}`})));
-        await Promise.all([...Array(50).keys()].map(_ => moderator.sendMessage(this.mjolnir.managementRoomId, {msgtype: 'm.text', body: '!mjolnir status'})));
+        await Promise.all([...Array(25).keys()].map((i) => moderator.sendMessage(this.mjolnir.managementRoomId, {msgtype: 'm.text.', body: `Irrelevant Message #${i}`})));
+        await Promise.all([...Array(25).keys()].map(_ => moderator.sendMessage(this.mjolnir.managementRoomId, {msgtype: 'm.text', body: '!mjolnir status'})));
 
         await moderator.sendMessage(this.mjolnir.managementRoomId, {msgtype: 'm.text', body: `!mjolnir rooms add ${targetRoom}`});
 
-        await Promise.all([...Array(50).keys()].map((i) => badUser.sendMessage(targetRoom, {msgtype: 'm.text.', body: `Bad Message #${i}`})));
+        await Promise.all([...Array(25).keys()].map((i) => badUser.sendMessage(targetRoom, {msgtype: 'm.text.', body: `Bad Message #${i}`})));
 
         try {
             await moderator.start();
@@ -72,6 +70,6 @@ describe("Test: Mjolnir can still sync and respond to commands while throttled",
                 }
             })
         });
-        assert.equal(count, 51, "There should be exactly 51 events from the spammer in this room.");
+        assert.equal(count, 26, "There should be exactly 26 events from the spammer in this room.");
     })
 })