catch bot rate limiting error, update tests

This commit is contained in:
Sharon Kennedy 2020-03-18 03:00:43 -04:00
parent 260bbbaf80
commit ef3c44f0d5
7 changed files with 156 additions and 242 deletions

3
.gitignore vendored
View File

@ -1,3 +1,4 @@
.env
node_modules
*.log
*.log
__mocks__/test_transcript.txt

View File

@ -19,8 +19,8 @@ export const mockRegisterRequest = jest
export const mockDeleteMultipleDevices = jest
.fn()
.mockImplementation((params) => {
if (!params.auth) {
.mockImplementation((devices, auth) => {
if (!auth) {
return Promise.reject({
data: { session: "session_id_1234" }
})

96
dist/bot.js vendored
View File

@ -244,6 +244,48 @@ function () {
value: function deleteOldDevices() {
var _this6 = this;
var doDelete = function doDelete(oldDevices) {
var auth = arguments.length > 1 && arguments[1] !== undefined ? arguments[1] : null;
var retries = arguments.length > 2 && arguments[2] !== undefined ? arguments[2] : 0;
if (retries > MAX_RETRIES) {
throw new Error("Exceeded max retries deleting old devices");
}
_logger["default"].log("info", "ATTEMPTING TO DELETE OLD DEVICES: ".concat(oldDevices));
_this6.client.deleteMultipleDevices(oldDevices, auth).then(function () {
return _logger["default"].log("info", "DELETED OLD DEVICES");
})["catch"](function (err) {
if (err['errcode'] === undefined && err['data']) {
var _auth = {
session: err.data.session,
type: "m.login.password",
user: process.env.BOT_USERID,
identifier: {
type: "m.id.user",
user: process.env.BOT_USERID
},
password: process.env.BOT_PASSWORD
};
doDelete(oldDevices, _auth);
} else if (err['errcode'] === 'M_LIMIT_EXCEEDED') {
var retryCount = retries + 1;
var delay = err['retry_after_ms'] ? err['retry_after_ms'] : retryCount * 1000;
_logger["default"].log("error", "RATE LIMIT EXCEEDED, RETRYING IN ".concat(delay, " MS"));
setTimeout(function () {
doDelete(oldDevices, auth, retryCount);
}, delay);
} else {
_logger["default"].log("error", "ERROR DELETING OLD DEVICES ON RETRY ".concat(retries, ": ").concat(JSON.stringify(err)));
doDelete(oldDevices, auth, retries + 1);
}
});
};
return this.client.getDevices().then(function (data) {
var currentDeviceId = _this6.client.getDeviceId();
@ -253,29 +295,41 @@ function () {
var oldDevices = allDeviceIds.filter(function (id) {
return id !== currentDeviceId;
});
doDelete(oldDevices);
})["catch"](function (err) {
_this6.handleBotCrash(undefined, err);
_logger["default"].log("info", "DELETING OLD DEVICES: ".concat(oldDevices));
_this6.client.deleteMultipleDevices(oldDevices)["catch"](function (err) {
var auth = {
session: err.data.session,
type: "m.login.password",
user: process.env.BOT_USERID,
identifier: {
type: "m.id.user",
user: process.env.BOT_USERID
},
password: process.env.BOT_PASSWORD
};
_this6.client.deleteMultipleDevices(oldDevices, auth).then(function () {
return _logger["default"].log("info", "DELETED OLD DEVICES");
})["catch"](function (err) {
return _logger["default"].log("error", "ERROR DELETING OLD DEVICES: ".concat(JSON.stringify(err.data)));
});
});
_logger["default"].log("error", "ERROR DELETING OLD DEVICES: ".concat(JSON.stringify(err.data)));
});
}
} // deleteOldDevices() {
// return this.client.getDevices().then(data => {
// const currentDeviceId = this.client.getDeviceId();
// const allDeviceIds = data.devices.map(d => d.device_id);
// const oldDevices = allDeviceIds.filter(id => id !== currentDeviceId);
// logger.log("info", `DELETING OLD DEVICES: ${oldDevices}`);
// this.client
// .deleteMultipleDevices(oldDevices)
// .catch(err => {
// const auth = {
// session: err.data.session,
// type: "m.login.password",
// user: process.env.BOT_USERID,
// identifier: { type: "m.id.user", user: process.env.BOT_USERID },
// password: process.env.BOT_PASSWORD
// };
// this.client
// .deleteMultipleDevices(oldDevices, auth)
// .then(() => logger.log("info", "DELETED OLD DEVICES"))
// .catch(err =>
// logger.log(
// "error",
// `ERROR DELETING OLD DEVICES: ${JSON.stringify(err.data)}`
// )
// );
// });
// });
// }
}, {
key: "setMembershipListeners",
value: function setMembershipListeners() {

192
dist/bot.test.js vendored
View File

@ -1,192 +0,0 @@
"use strict";
function _typeof(obj) { "@babel/helpers - typeof"; if (typeof Symbol === "function" && typeof Symbol.iterator === "symbol") { _typeof = function _typeof(obj) { return typeof obj; }; } else { _typeof = function _typeof(obj) { return obj && typeof Symbol === "function" && obj.constructor === Symbol && obj !== Symbol.prototype ? "symbol" : typeof obj; }; } return _typeof(obj); }
var path = _interopRequireWildcard(require("path"));
var os = _interopRequireWildcard(require("os"));
var _waitForExpect = _interopRequireDefault(require("wait-for-expect"));
var _matrixJsSdk = require("matrix-js-sdk");
var _bot = _interopRequireDefault(require("./bot"));
function _interopRequireDefault(obj) { return obj && obj.__esModule ? obj : { "default": obj }; }
function _getRequireWildcardCache() { if (typeof WeakMap !== "function") return null; var cache = new WeakMap(); _getRequireWildcardCache = function _getRequireWildcardCache() { return cache; }; return cache; }
function _interopRequireWildcard(obj) { if (obj && obj.__esModule) { return obj; } if (obj === null || _typeof(obj) !== "object" && typeof obj !== "function") { return { "default": obj }; } var cache = _getRequireWildcardCache(); if (cache && cache.has(obj)) { return cache.get(obj); } var newObj = {}; var hasPropertyDescriptor = Object.defineProperty && Object.getOwnPropertyDescriptor; for (var key in obj) { if (Object.prototype.hasOwnProperty.call(obj, key)) { var desc = hasPropertyDescriptor ? Object.getOwnPropertyDescriptor(obj, key) : null; if (desc && (desc.get || desc.set)) { Object.defineProperty(newObj, key, desc); } else { newObj[key] = obj[key]; } } } newObj["default"] = obj; if (cache) { cache.set(obj, newObj); } return newObj; }
require('dotenv').config();
describe('OcrccBot', function () {
beforeEach(function () {
_matrixJsSdk.createClient.mockClear();
_matrixJsSdk.mockInitCrypto.mockClear();
_matrixJsSdk.mockStartClient.mockClear();
_matrixJsSdk.mockRegisterRequest.mockClear();
_matrixJsSdk.mockSetPowerLevel.mockClear();
_matrixJsSdk.mockCreateRoom.mockClear();
_matrixJsSdk.mockLeave.mockClear();
_matrixJsSdk.mockDeactivateAccount.mockClear();
_matrixJsSdk.mockStopClient.mockClear();
_matrixJsSdk.mockClearStores.mockClear();
_matrixJsSdk.mockOnce.mockClear();
_matrixJsSdk.mockOn.mockClear();
_matrixJsSdk.mockLogin.mockClear();
_matrixJsSdk.mockGetDevices.mockClear();
_matrixJsSdk.mockGetDeviceId.mockClear();
_matrixJsSdk.mockDeleteMultipleDevices.mockClear();
_matrixJsSdk.mockGetJoinedRooms.mockClear();
_matrixJsSdk.mockSetDeviceVerified.mockClear();
_matrixJsSdk.mockInvite.mockClear();
_matrixJsSdk.mockKick.mockClear();
_matrixJsSdk.mockGetJoinedRoomMembers.mockClear();
_matrixJsSdk.mockGetUser.mockClear();
});
test('constructor should inititialize matrix client', function () {
var bot = new _bot["default"]();
expect(_matrixJsSdk.createClient).toHaveBeenCalledWith(process.env.MATRIX_SERVER_URL);
expect(bot.joinedRooms).toEqual([]);
expect(bot.awaitingFacilitator).toEqual({});
expect(bot.activeChatrooms).toEqual({});
});
test('#createLocalStorage should have correct storage location', function () {
var bot = new _bot["default"]();
var localStorage = bot.createLocalStorage();
var localStoragePath = path.resolve(path.join(os.homedir(), ".local-storage", "matrix-chatbot-".concat(process.env.BOT_USERNAME)));
expect(localStorage._location).toBe(localStoragePath);
});
test('#sendMessage should send a text message', function () {
var bot = new _bot["default"]();
bot.start();
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockStartClient).toHaveBeenCalled();
});
var testRoom = 'room_id_1234';
var testMsg = 'test message';
bot.sendMessage(testRoom, testMsg);
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockSetDeviceVerified).toHaveBeenCalledTimes(2);
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockSendTextMessage).toHaveBeenCalledWith(testRoom, testMsg);
});
});
test('#inviteUserToRoom should add member to room and retry on rate limit error', function () {
var bot = new _bot["default"]();
bot.start();
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockStartClient).toHaveBeenCalled();
});
bot.inviteUserToRoom(bot.client, 'room_id_1234', process.env.BOT_USERNAME);
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockInvite).toHaveBeenCalledTimes(2);
});
});
test('#kickUserFromRoom should remove member from room and retry on rate limit error', function () {
var bot = new _bot["default"]();
bot.start();
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockStartClient).toHaveBeenCalled();
});
bot.kickUserFromRoom(bot.client, 'room_id_1234', process.env.BOT_USERNAME);
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockKick).toHaveBeenCalledTimes(2);
});
});
test('#inviteFacilitators should invite all members from Facilitator room', function () {
var bot = new _bot["default"]();
bot.start();
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockStartClient).toHaveBeenCalled();
});
bot.inviteFacilitators();
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockGetJoinedRoomMembers).toHaveBeenCalledWith(process.env.FACILITATOR_ROOM_ID);
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockGetUser).toHaveBeenCalledTimes(2);
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockInvite).toHaveBeenCalledTimes(2);
});
});
test('#uninviteFacilitators should remove all members that have not accepted the invite', function () {
var bot = new _bot["default"]();
bot.start();
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockStartClient).toHaveBeenCalled();
});
bot.uninviteFacilitators();
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockGetJoinedRoomMembers).toHaveBeenCalledWith(process.env.FACILITATOR_ROOM_ID);
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockGetJoinedRoomMembers).toHaveBeenCalledWith('room_id_1234');
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockKick).toHaveBeenCalled();
});
});
test('#handleBotCrash should notify rooms', function () {});
test('#writeToTranscript should parse event and write to transcript file', function () {});
test('#deleteOldDevices should delete old sessions', function () {}); // TODO test listeners for membership events and message events
test('#start should start bot and set up listeners', function () {
var bot = new _bot["default"]();
bot.start();
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockLogin).toHaveBeenCalled();
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.WebStorageSessionStore).toHaveBeenCalled();
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.createClient).toHaveBeenCalled();
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockGetDevices).toHaveBeenCalled();
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockGetDeviceId).toHaveBeenCalled();
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockDeleteMultipleDevices).toHaveBeenCalled();
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockInitCrypto).toHaveBeenCalled();
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockGetJoinedRooms).toHaveBeenCalled();
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockOn).toHaveBeenCalled();
});
(0, _waitForExpect["default"])(function () {
expect(_matrixJsSdk.mockStartClient).toHaveBeenCalled();
});
});
});

View File

@ -30,5 +30,8 @@
"jest-cli": "^25.1.0",
"nodemon": "^2.0.2",
"wait-for-expect": "^3.0.2"
},
"jest": {
"testPathIgnorePatterns": ["dist"]
}
}

View File

@ -198,14 +198,15 @@ class OcrccBot {
}
deleteOldDevices() {
return this.client.getDevices().then(data => {
const currentDeviceId = this.client.getDeviceId();
const allDeviceIds = data.devices.map(d => d.device_id);
const oldDevices = allDeviceIds.filter(id => id !== currentDeviceId);
logger.log("info", `DELETING OLD DEVICES: ${oldDevices}`);
this.client
.deleteMultipleDevices(oldDevices)
.catch(err => {
const doDelete = (oldDevices, auth=null, retries=0) => {
if (retries > MAX_RETRIES) {
throw new Error("Exceeded max retries deleting old devices")
}
logger.log("info", `ATTEMPTING TO DELETE OLD DEVICES: ${oldDevices}`);
this.client.deleteMultipleDevices(oldDevices, auth)
.then(() => logger.log("info", "DELETED OLD DEVICES"))
.catch(err => {
if (err['errcode'] === undefined && err['data']) {
const auth = {
session: err.data.session,
type: "m.login.password",
@ -213,23 +214,67 @@ class OcrccBot {
identifier: { type: "m.id.user", user: process.env.BOT_USERID },
password: process.env.BOT_PASSWORD
};
this.client
.deleteMultipleDevices(oldDevices, auth)
.then(() => logger.log("info", "DELETED OLD DEVICES"))
.catch(err =>
// TODO: catch rate limiting error and retry
// if (err.errcode === "M_LIMIT_EXCEEDED") {
// setTimeout(err.retry_after_ms)
// }
logger.log(
"error",
`ERROR DELETING OLD DEVICES: ${JSON.stringify(err.data)}`
)
);
doDelete(oldDevices, auth)
} else if (err['errcode'] === 'M_LIMIT_EXCEEDED') {
const retryCount = retries + 1
const delay = err['retry_after_ms'] ? err['retry_after_ms'] : retryCount * 1000
logger.log("error", `RATE LIMIT EXCEEDED, RETRYING IN ${delay} MS`);
setTimeout(() => {
doDelete(oldDevices, auth, retryCount)
}, delay)
} else {
logger.log("error", `ERROR DELETING OLD DEVICES ON RETRY ${retries}: ${JSON.stringify(err)}`)
doDelete(oldDevices, auth, retries + 1)
}
})
}
return this.client.getDevices()
.then(data => {
const currentDeviceId = this.client.getDeviceId();
const allDeviceIds = data.devices.map(d => d.device_id);
const oldDevices = allDeviceIds.filter(id => id !== currentDeviceId);
doDelete(oldDevices)
})
.catch(err => {
this.handleBotCrash(undefined, err);
logger.log(
"error",
`ERROR DELETING OLD DEVICES: ${JSON.stringify(err.data)}`
)
});
});
}
// deleteOldDevices() {
// return this.client.getDevices().then(data => {
// const currentDeviceId = this.client.getDeviceId();
// const allDeviceIds = data.devices.map(d => d.device_id);
// const oldDevices = allDeviceIds.filter(id => id !== currentDeviceId);
// logger.log("info", `DELETING OLD DEVICES: ${oldDevices}`);
// this.client
// .deleteMultipleDevices(oldDevices)
// .catch(err => {
// const auth = {
// session: err.data.session,
// type: "m.login.password",
// user: process.env.BOT_USERID,
// identifier: { type: "m.id.user", user: process.env.BOT_USERID },
// password: process.env.BOT_PASSWORD
// };
// this.client
// .deleteMultipleDevices(oldDevices, auth)
// .then(() => logger.log("info", "DELETED OLD DEVICES"))
// .catch(err =>
// logger.log(
// "error",
// `ERROR DELETING OLD DEVICES: ${JSON.stringify(err.data)}`
// )
// );
// });
// });
// }
setMembershipListeners() {
// Automatically accept all room invitations
return this.client.on("RoomMember.membership", (event, member) => {

View File

@ -35,8 +35,11 @@ import {
import OcrccBot from './bot'
describe('OcrccBot', () => {
const mockAppendFileSync = jest.fn()
fs.appendFileSync = mockAppendFileSync
describe('OcrccBot', () => {
beforeEach(() => {
createClient.mockClear()
mockInitCrypto.mockClear()
@ -61,6 +64,7 @@ describe('OcrccBot', () => {
mockGetJoinedRoomMembers.mockClear()
mockGetUser.mockClear()
mockSendTextMessage.mockClear()
mockAppendFileSync.mockClear()
})
test('constructor should inititialize matrix client', () => {
@ -196,11 +200,10 @@ describe('OcrccBot', () => {
})
test('#writeToTranscript should parse event and write to transcript file', () => {
const appendFileSyncSpy = jest.spyOn(fs, 'appendFileSync')
const bot = new OcrccBot()
bot.start()
bot.activeChatrooms['test_room_id'] = { transcriptFile: 'test filepath' }
bot.activeChatrooms['test_room_id'] = { transcriptFile: '__mocks__/test_transcript.txt' }
waitForExpect(() => {
expect(mockStartClient).toHaveBeenCalled()
@ -216,7 +219,7 @@ describe('OcrccBot', () => {
bot.writeToTranscript(mockEvent)
waitForExpect(() => {
expect(appendFileSyncSpy).toHaveBeenCalledWith('test filepath', 'test_sender [00:00:00]: test content', 'utf8')
expect(mockAppendFileSync).toHaveBeenCalledWith('__mocks__/test_transcript.txt', 'test_sender [00:00:00]: test content', 'utf8')
})
})