Skip to content

Commit

Permalink
Catch exceptions in reticulum events and add some more logging and stats
Browse files Browse the repository at this point in the history
  • Loading branch information
keianhzo committed Dec 11, 2020
1 parent 1b38b88 commit b81dfd0
Show file tree
Hide file tree
Showing 6 changed files with 133 additions and 99 deletions.
4 changes: 2 additions & 2 deletions .env.defaults
Original file line number Diff line number Diff line change
Expand Up @@ -18,10 +18,10 @@ HUBS_HOSTS=localhost,hubs.local
HUBS_HOOK=Hubs

# The shard ID for this client. (1 if you aren't using multiple shards.)
SHARD_ID=0
SHARD_ID=1

# The shard count for this client. (1 if you aren't using multiple shards.)
SHARD_COUNT=0
SHARD_COUNT=1

# The BCP 47 locale for bot output.
LOCALE=en-US
Expand Down
4 changes: 2 additions & 2 deletions habitat/default.toml
Original file line number Diff line number Diff line change
Expand Up @@ -5,8 +5,8 @@ statsd_host = "localhost:8125"
statsd_prefix = "discordbot."
hubs_hosts = "localhost,hubs.local"
hubs_hook = "Hubs"
shard_id = "0"
shard_count = "0"
shard_id = "1"
shard_count = "1"
verbose = "false"
locale = "en-US"
timezone = "America/Los_Angeles"
Expand Down
2 changes: 1 addition & 1 deletion habitat/plan.sh
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
pkg_name=hubs-discord-bot
pkg_origin=mozillareality
pkg_maintainer="Mozilla Mixed Reality <[email protected]>"
pkg_version="0.0.2"
pkg_version="0.0.5"
pkg_license=('MPL2')
pkg_description="Discord bot for Hubs by Mozilla"

Expand Down
4 changes: 2 additions & 2 deletions package-lock.json

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

4 changes: 2 additions & 2 deletions package.json
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
{
"name": "hubs-discord-bot",
"version": "0.0.2",
"version": "0.0.5",
"description": "A Discord bot that does helpful things related to Hubs rooms.",
"repository": "github:MozillaReality/hubs-discord-bot",
"main": "src/index.js",
Expand Down Expand Up @@ -36,4 +36,4 @@
"eslint-plugin-node": "^10.0.0",
"tape": "^4.11.0"
}
}
}
214 changes: 124 additions & 90 deletions src/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -67,9 +67,7 @@ class DiscordEventQueue {
}

_onSizeChanged() {
if (VERBOSE) {
console.log(`Event queue [${this.id}] size: ${this.size}`);
}
console.log(`Event queue [${this.id}] size: ${this.size}`);
}

// Enqueues the given function to run as soon as no other functions are currently running.
Expand All @@ -79,7 +77,7 @@ class DiscordEventQueue {
return (this.curr = this.curr
.then(_ => fn())
.catch(e => {
console.error(ts(e.stack));
console.error(`Event queue [${this.id}] exception: ${ts(e.stack)}`);
})
.finally(() => {
this.size -= 1;
Expand Down Expand Up @@ -267,120 +265,144 @@ async function establishBridging(hubState, bridges) {

const lastPresenceMessages = {}; // { discordCh: message object }
presenceRollups.on('new', ({ kind, users, fresh }) => {
if (statsdClient != null) {
statsdClient.send("reticulum.presencechanges", 1, "c");
}
for (const discordCh of bridges.getChannels(hubState.id).values()) {
if (VERBOSE) {
console.debug(ts(`Relaying presence ${kind} in ${hubState.id} to ${formatDiscordCh(discordCh)}.`));
}
if (kind === "arrive") {
const msg = fresh ?
`${formatList(users)} joined the Hubs room. Join them: ${hubState.shortUrl}` :
`${formatList(users)} joined the Hubs room.`;
lastPresenceMessages[discordCh.id] = discordCh.send(msg);
} else if (kind === "depart") {
const msg = `${formatList(users)} left the Hubs room.`;
lastPresenceMessages[discordCh.id] = discordCh.send(msg);
} else if (kind === "rename") {
lastPresenceMessages[discordCh.id] = discordCh.send(formatRename(users[0]));
try {
if (statsdClient != null) {
statsdClient.send("reticulum.presencechanges", 1, "c");
}
for (const discordCh of bridges.getChannels(hubState.id).values()) {
if (VERBOSE) {
console.debug(ts(`Relaying presence ${kind} in ${hubState.id} to ${formatDiscordCh(discordCh)}.`));
}
if (kind === "arrive") {
const msg = fresh ?
`${formatList(users)} joined the Hubs room. Join them: ${hubState.shortUrl}` :
`${formatList(users)} joined the Hubs room.`;
lastPresenceMessages[discordCh.id] = discordCh.send(msg);
} else if (kind === "depart") {
const msg = `${formatList(users)} left the Hubs room.`;
lastPresenceMessages[discordCh.id] = discordCh.send(msg);
} else if (kind === "rename") {
lastPresenceMessages[discordCh.id] = discordCh.send(formatRename(users[0]));
}
}
} catch (e) {
console.error(ts(`Error relaying presence ${kind} in ${hubState.id}.`), e);
}
});
presenceRollups.on('update', ({ kind, users, fresh }) => {
if (statsdClient != null) {
statsdClient.send("reticulum.presencechanges", 1, "c");
}
for (const discordCh of bridges.getChannels(hubState.id).values()) {
if (VERBOSE) {
console.debug(ts(`Relaying presence ${kind} in ${hubState.id} to ${formatDiscordCh(discordCh)}.`));
}
if (kind === "arrive") {
const msg = fresh ?
`${formatList(users)} joined the Hubs room. Join them: ${hubState.shortUrl}` :
`${formatList(users)} joined the Hubs room.`;
lastPresenceMessages[discordCh.id] = lastPresenceMessages[discordCh.id].then(prev => prev.edit(msg));
} else if (kind === "depart") {
const msg = `${formatList(users)} left the Hubs room.`;
lastPresenceMessages[discordCh.id] = lastPresenceMessages[discordCh.id].then(prev => prev.edit(msg));
} else if (kind === "rename") {
lastPresenceMessages[discordCh.id] = lastPresenceMessages[discordCh.id].then(prev => prev.edit(formatRename(users[0])));
try {
if (statsdClient != null) {
statsdClient.send("reticulum.presencechanges", 1, "c");
}
for (const discordCh of bridges.getChannels(hubState.id).values()) {
if (VERBOSE) {
console.debug(ts(`Relaying presence ${kind} in ${hubState.id} to ${formatDiscordCh(discordCh)}.`));
}
if (kind === "arrive") {
const msg = fresh ?
`${formatList(users)} joined the Hubs room. Join them: ${hubState.shortUrl}` :
`${formatList(users)} joined the Hubs room.`;
lastPresenceMessages[discordCh.id] = lastPresenceMessages[discordCh.id].then(prev => prev.edit(msg));
} else if (kind === "depart") {
const msg = `${formatList(users)} left the Hubs room.`;
lastPresenceMessages[discordCh.id] = lastPresenceMessages[discordCh.id].then(prev => prev.edit(msg));
} else if (kind === "rename") {
lastPresenceMessages[discordCh.id] = lastPresenceMessages[discordCh.id].then(prev => prev.edit(formatRename(users[0])));
}
}
} catch (e) {
console.error(ts(`Error relaying presence update ${kind} in ${hubState.id}.`), e);
}
});

reticulumCh.on('rescene', (timestamp, id, whom, scene) => {
for (const discordCh of bridges.getChannels(hubState.id).values()) {
if (VERBOSE) {
console.debug(ts(`Relaying scene change by ${whom} (${id}) in ${hubState.id} to ${formatDiscordCh(discordCh)}.`));
}
if (scene) {
discordCh.send(`${whom} changed the scene in ${hubState.shortUrl} to ${scene.name}.`);
} else {
// the API response has a totally convoluted structure we could use to dig up the scene URL in theory,
// but it doesn't seem worth reproducing the dozen lines of hubs code that does this here
discordCh.send(`${whom} changed ${hubState.shortUrl} to a new scene.`);
try {
for (const discordCh of bridges.getChannels(hubState.id).values()) {
if (VERBOSE) {
console.debug(ts(`Relaying scene change by ${whom} (${id}) in ${hubState.id} to ${formatDiscordCh(discordCh)}.`));
}
if (scene) {
discordCh.send(`${whom} changed the scene in ${hubState.shortUrl} to ${scene.name}.`);
} else {
// the API response has a totally convoluted structure we could use to dig up the scene URL in theory,
// but it doesn't seem worth reproducing the dozen lines of hubs code that does this here
discordCh.send(`${whom} changed ${hubState.shortUrl} to a new scene.`);
}
}
} catch (e) {
console.error(ts(`Error relaying presence scene change by ${whom} (${id}) in ${hubState.id}.`), e);
}
});
reticulumCh.on('renamehub', (timestamp, id, whom, name, slug) => {
for (const discordCh of bridges.getChannels(hubState.id).values()) {
hubState.name = name;
hubState.slug = slug;
if (VERBOSE) {
console.debug(ts(`Relaying name change by ${whom} (${id}) in ${hubState.id} to ${formatDiscordCh(discordCh)}.`));
try {
for (const discordCh of bridges.getChannels(hubState.id).values()) {
hubState.name = name;
hubState.slug = slug;
if (VERBOSE) {
console.debug(ts(`Relaying name change by ${whom} (${id}) in ${hubState.id} to ${formatDiscordCh(discordCh)}.`));
}
discordCh.send(`${whom} renamed the Hubs room at ${hubState.shortUrl} to ${hubState.name}.`);
}
discordCh.send(`${whom} renamed the Hubs room at ${hubState.shortUrl} to ${hubState.name}.`);
} catch (e) {
console.error(ts(`Error relaying name change by ${whom} (${id}) in ${hubState.id}.`), e);
}
});

const mediaBroadcasts = {}; // { url: timestamp }
reticulumCh.on("message", (timestamp, id, whom, type, body) => {
if (statsdClient != null) {
statsdClient.send("reticulum.contentmsgs", 1, "c");
}
if (type === "media") {
// we really like to deduplicate media broadcasts of the same object in short succession,
// mostly because of the case where people are repositioning pinned media, but also because
// sometimes people will want to clone a bunch of one thing and pin them all in one go
const lastBroadcast = mediaBroadcasts[body.src];
if (lastBroadcast != null) {
const elapsedMs = timestamp - lastBroadcast;
if (elapsedMs <= MEDIA_DEDUPLICATE_MS) {
try {
if (statsdClient != null) {
statsdClient.send("reticulum.contentmsgs", 1, "c");
}
if (type === "media") {
// we really like to deduplicate media broadcasts of the same object in short succession,
// mostly because of the case where people are repositioning pinned media, but also because
// sometimes people will want to clone a bunch of one thing and pin them all in one go
const lastBroadcast = mediaBroadcasts[body.src];
if (lastBroadcast != null) {
const elapsedMs = timestamp - lastBroadcast;
if (elapsedMs <= MEDIA_DEDUPLICATE_MS) {
if (VERBOSE) {
console.debug(ts(`Declining to rebroadcast ${body.src} only ${(elapsedMs / 1000).toFixed(0)} second(s) after previous broadcast.`));
}
return;
}
} else {
mediaBroadcasts[body.src] = timestamp;
}
}
for (const discordCh of bridges.getChannels(hubState.id).values()) {
const webhook = ACTIVE_WEBHOOKS[discordCh.id]; // note that this may change over the lifetime of the bridge
if (webhook == null) {
if (VERBOSE) {
console.debug(ts(`Declining to rebroadcast ${body.src} only ${(elapsedMs / 1000).toFixed(0)} second(s) after previous broadcast.`));
console.debug(`Ignoring message of type ${type} in ${formatDiscordCh(discordCh)} because no webhook is associated.`);
}
return;
}
} else {
mediaBroadcasts[body.src] = timestamp;
}
}
for (const discordCh of bridges.getChannels(hubState.id).values()) {
const webhook = ACTIVE_WEBHOOKS[discordCh.id]; // note that this may change over the lifetime of the bridge
if (webhook == null) {
if (VERBOSE) {
console.debug(`Ignoring message of type ${type} in ${formatDiscordCh(discordCh)} because no webhook is associated.`);
const msg = ts(`Relaying message of type ${type} from ${whom} (${id}) via ${hubState.id} to ${formatDiscordCh(discordCh)}: %j`);
console.debug(msg, body);
}
if (type === "chat") {
webhook.send(body, { username: whom });
} else if (type === "media") {
webhook.send(body.src, { username: whom });
} else if (type === "photo" || type == "video") {
// we like to just broadcast all camera photos and videos, without waiting for anyone to pin them
webhook.send(body.src, { username: whom });
}
return;
}
if (VERBOSE) {
const msg = ts(`Relaying message of type ${type} from ${whom} (${id}) via ${hubState.id} to ${formatDiscordCh(discordCh)}: %j`);
console.debug(msg, body);
}
if (type === "chat") {
webhook.send(body, { username: whom });
} else if (type === "media") {
webhook.send(body.src, { username: whom });
} else if (type === "photo" || type == "video") {
// we like to just broadcast all camera photos and videos, without waiting for anyone to pin them
webhook.send(body.src, { username: whom });
}
} catch (e) {
console.error(ts(`Error relaying message of type ${type} from ${whom} (${id}) via ${hubState.id}.`), e);
}
});

reticulumCh.on('sync', async () => {
await updateChannelPresenceIcons(bridges.getChannels(hubState.id).values(), reticulumCh.getUserCount() > 0);
try {
await updateChannelPresenceIcons(bridges.getChannels(hubState.id).values(), reticulumCh.getUserCount() > 0);
} catch (e) {
console.error(ts(`Error updating channel presence icons in ${hubState.id}`), e);
}
});

// also get it right for the initial state
Expand Down Expand Up @@ -562,12 +584,21 @@ async function start() {
}
const hubState = bridges.getHub(msg.channel.id);
const description = hubState != null ? `the Hubs room: ${hubState.shortUrl}` : "a Hubs room.";
await msg.channel.send(`@here Hey! You should join ${description}`, { disableEveryone: false });
await msg.unpin();
try {
await msg.channel.send(`@here Hey! You should join ${description}`, { disableEveryone: false });
await msg.unpin();
} catch(e) {
console.error(ts(`Error sending notification in channel ${formatDiscordCh(msg.channel)}:`), e);
}
});

// Gets debug event and some rate limit events in the shape of a 429 message (ie. set channel topic)
discordClient.on("debug", (...args) => {
if (args[0].startsWith("429")) {
if (statsdClient != null) {
statsdClient.send("discord.error429", 1, "c");
}
}
console.log("Debug: ", ...args);
});

Expand All @@ -579,6 +610,9 @@ async function start() {
console.log(`\tmethod: ${info.method}`);
console.log(`\tpath: ${info.path}`);
console.log(`\troute: ${info.route}`);
if (statsdClient != null) {
statsdClient.send("discord.rateLimit", 1, "c");
}
});

discordClient.on('webhookUpdate', (discordCh) => {
Expand Down

0 comments on commit b81dfd0

Please sign in to comment.