Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add sqlite logging and reloading messages #1839

Merged
merged 4 commits into from
Mar 9, 2018
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 13 additions & 0 deletions defaults/config.js
Original file line number Diff line number Diff line change
Expand Up @@ -148,6 +148,19 @@ module.exports = {
// @default null
webirc: null,

//
// Message logging
// Logging is also controlled per user individually (logs variable)
// Leave the array empty to disable all logging globally
//
// text: Text file per network/channel in user folder
// sqlite: Messages are stored in SQLite, this allows them to be reloaded on server restart
//
// @type array
// @default ["sqlite", "text"]
//
messageStorage: ["sqlite", "text"],

//
// Log settings
//
Expand Down
2 changes: 2 additions & 0 deletions package.json
Original file line number Diff line number Diff line change
Expand Up @@ -56,9 +56,11 @@
"semver": "5.5.0",
"socket.io": "2.0.4",
"spdy": "3.4.7",
"sqlite3": "3.1.13",
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For good measure, I went through a couple of their (many) open issues, and oh boy does it feel like node-ldapjs again (if I'm reading the following tickets correctly):

Ouch.
Note that I'm not trying to make some sort of a point with this comment, just documenting findings. Just like when we introduced LDAP support that got us a few install-related tickets, we might have to face issues related to installs, especially if this is not compatible with v8/v9!

Just putting this out there, someone mentioned https://github.com/JoshuaWise/better-sqlite3 as an alternative 🤷‍♂️

Given all those, I think we really want some minimal tests around writing/loading logs, so that all supported Node versions and Linux/Windows support get some confidence that this is working.
Thoughts?

"thelounge-ldapjs-non-maintained-fork": "1.0.2",
"ua-parser-js": "0.7.17",
"urijs": "1.19.1",
"uuid": "3.2.1",
"web-push": "3.3.0",
"yarn": "1.5.1"
},
Expand Down
15 changes: 14 additions & 1 deletion src/client.js
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ const Network = require("./models/network");
const ircFramework = require("irc-framework");
const Helper = require("./helper");
const UAParser = require("ua-parser-js");
const MessageStorage = require("./plugins/sqlite");
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is it on purpose that MessageStorage == sqlite.js? I'm fine if so, just a sanity check in case it was forgotten with a rebase or something.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah this is correct.


module.exports = Client;

Expand Down Expand Up @@ -78,8 +79,16 @@ function Client(manager, name, config = {}) {
});

const client = this;

let delay = 0;

if (!Helper.config.public) {
client.messageStorage = new MessageStorage();

if (client.config.log && Helper.config.messageStorage.includes("sqlite")) {
client.messageStorage.enable(client.name);
}
}

(client.config.networks || []).forEach((n) => {
setTimeout(function() {
client.connect(n);
Expand Down Expand Up @@ -174,6 +183,7 @@ Client.prototype.connect = function(args) {
args.hostname = args.hostname || (client.config && client.config.hostname) || client.hostname;

const network = new Network({
uuid: args.uuid,
name: args.name || (Helper.config.displayNetwork ? "" : Helper.config.defaults.name) || "",
host: args.host || "",
port: parseInt(args.port, 10) || (args.tls ? 6697 : 6667),
Expand Down Expand Up @@ -261,6 +271,7 @@ Client.prototype.connect = function(args) {

network.irc.requestCap([
"znc.in/self-message", // Legacy echo-message for ZNc
"znc.in/playback", // http://wiki.znc.in/Playback
]);

events.forEach((plugin) => {
Expand All @@ -273,6 +284,8 @@ Client.prototype.connect = function(args) {
network.irc.connect();

client.save();

channels.forEach((channel) => channel.loadMessages(client, network));
};

Client.prototype.generateToken = function(callback) {
Expand Down
91 changes: 76 additions & 15 deletions src/models/chan.js
Original file line number Diff line number Diff line change
Expand Up @@ -63,11 +63,7 @@ Chan.prototype.pushMessage = function(client, msg, increasesUnread) {
return;
}

this.messages.push(msg);

if (client.config.log === true) {
writeUserLog.call(this, client, msg);
}
this.writeUserLog(client, msg);

if (Helper.config.maxHistory >= 0 && this.messages.length > Helper.config.maxHistory) {
const deleted = this.messages.splice(0, this.messages.length - Helper.config.maxHistory);
Expand Down Expand Up @@ -183,21 +179,86 @@ Chan.prototype.getFilteredClone = function(lastActiveChannel, lastMessage) {
}, {});
};

function writeUserLog(client, msg) {
if (!msg.isLoggable()) {
return false;
Chan.prototype.writeUserLog = function(client, msg) {
this.messages.push(msg);

// Does this user have logs disabled
if (!client.config.log) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see you already do this check in src/client.js L87, should we do it again, or instead check that a message store was enabled?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

src/client.js check is for sqlite only, while this check here ensures no logging is performed for any method (sqlite or text). It will most likely become clearer when the logging API is abstracted out.

return;
}

// Are logs disabled server-wide
if (Helper.config.messageStorage.length === 0) {
return;
}

// Is this particular message or channel loggable
if (!msg.isLoggable() || !this.isLoggable()) {
return;
}

// Find the parent network where this channel is in
const target = client.find(this.id);

if (!target) {
return false;
return;
}

// TODO: Something more pluggable
if (Helper.config.messageStorage.includes("sqlite")) {
client.messageStorage.index(target.network.uuid, this.name, msg);
}

if (Helper.config.messageStorage.includes("text")) {
userLog.write(
client.name,
target.network.host, // TODO: Fix #1392, multiple connections to same server results in duplicate logs
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Your PR description says the first commit fixes #1392, is it still TODO?

Copy link
Member Author

@xPaw xPaw Mar 4, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It fixes it in the case of sqlite, I didn't change it for text logging because that would change the logging folder (which is breaking, and out of the scope of this PR).

The fix would be changing network.host to network.uuid on that line, but that will start logging into a new folder.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, then we either need to reword the PR description, or remember to re-open the issue after this is merged, as it will auto-close #1392.

this.type === Chan.Type.LOBBY ? target.network.host : this.name,
msg
);
}
};

Chan.prototype.loadMessages = function(client, network) {
if (!client.messageStorage || !this.isLoggable()) {
return;
}

client.messageStorage
.getMessages(network, this)
.then((messages) => {
if (messages.length === 0) {
if (network.irc.network.cap.isEnabled("znc.in/playback")) {
requestZncPlayback(this, network, 0);
}

return;
}

this.messages.unshift(...messages);

if (!this.firstUnread) {
this.firstUnread = messages[messages.length - 1].id;
}

client.emit("more", {
chan: this.id,
messages: messages.slice(-100),
});

if (network.irc.network.cap.isEnabled("znc.in/playback")) {
const from = Math.floor(messages[messages.length - 1].time.getTime() / 1000);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So is this from the last message we have in the logs until present?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yep.


requestZncPlayback(this, network, from);
}
})
.catch((err) => log.error(`Failed to load messages: ${err}`));
};

Chan.prototype.isLoggable = function() {
return this.type === Chan.Type.CHANNEL || this.type === Chan.Type.QUERY;
};

userLog.write(
client.name,
target.network.host, // TODO: Fix #1392, multiple connections to same server results in duplicate logs
this.type === Chan.Type.LOBBY ? target.network.host : this.name,
msg
);
function requestZncPlayback(channel, network, from) {
network.irc.raw("ZNC", "*playback", "PLAY", channel.name, from.toString());
}
1 change: 1 addition & 0 deletions src/models/msg.js
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@ class Msg {

isLoggable() {
return this.type !== Msg.Type.MOTD &&
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I didn't realize we didn't log motds, maybe we should?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That would be pretty spammy in the lobby network.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There's no reason to log MOTD. It's meant to be something that is just around for your current connection. On reconnect, you'll get the new MOTD, so the only time you won't have the MOTD is when you are currently disconnected from the IRC server.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I guess I'm expecting servers to update their MOTDs frequently, which is definitely not extremely usual. But for example, I like being able to refer to older Freenode MOTDs, as they display news / info in there (for example about their conference), but it might be too niche and/or not worth it.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I feel like the advantages of this for a few people would be outweighed by the confusion of having multiple motds appearing when you start the lounge, personally. But I don't feel about it strongly.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah that's a good conclusion. I do see benefits in keeping track of older MOTDs, but you're right that the benefits do not outweigh the drawbacks. Another thing that I'm happy to see what feedbacks we get, i.e. if we ever get users confused by this or not, and we can then rethink this.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, if people find it confusing, happy to revisit.

this.type !== Msg.Type.ERROR &&
this.type !== Msg.Type.BANLIST &&
this.type !== Msg.Type.WHOIS;
}
Expand Down
6 changes: 6 additions & 0 deletions src/models/network.js
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
"use strict";

const _ = require("lodash");
const uuidv4 = require("uuid/v4");
const Chan = require("./chan");

module.exports = Network;
Expand Down Expand Up @@ -42,6 +43,10 @@ function Network(attr) {
chanCache: [],
});

if (!this.uuid) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do we need to check for previous ids?

Copy link
Member Author

@xPaw xPaw Mar 2, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I didn't want to always call uuid() in default object as it would waste the call when loading an existing network.

this.uuid = uuidv4();
}

if (!this.name) {
this.name = this.host;
}
Expand Down Expand Up @@ -125,6 +130,7 @@ Network.prototype.getNetworkStatus = function() {

Network.prototype.export = function() {
const network = _.pick(this, [
"uuid",
"awayMessage",
"nick",
"name",
Expand Down
1 change: 1 addition & 0 deletions src/plugins/inputs/query.js
Original file line number Diff line number Diff line change
Expand Up @@ -54,4 +54,5 @@ exports.input = function(network, chan, cmd, args) {
shouldOpen: true,
});
this.save();
newChan.loadMessages(this, network);
};
2 changes: 2 additions & 0 deletions src/plugins/irc-events/join.js
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,8 @@ module.exports = function(irc, network) {
chan: chan.getFilteredClone(true),
});

chan.loadMessages(client, network);

// Request channels' modes
network.irc.raw("MODE", chan.name);
} else if (data.nick === irc.user.nick) {
Expand Down
1 change: 1 addition & 0 deletions src/plugins/irc-events/message.js
Original file line number Diff line number Diff line change
Expand Up @@ -72,6 +72,7 @@ module.exports = function(irc, network) {
network: network.id,
chan: chan.getFilteredClone(true),
});
chan.loadMessages(client, network);
}
}

Expand Down
1 change: 1 addition & 0 deletions src/plugins/irc-events/whois.js
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ module.exports = function(irc, network) {
network: network.id,
chan: chan.getFilteredClone(true),
});
chan.loadMessages(client, network);
}

let msg;
Expand Down
126 changes: 126 additions & 0 deletions src/plugins/sqlite.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,126 @@
"use strict";

const path = require("path");
const fsextra = require("fs-extra");
const sqlite3 = require("sqlite3");
const Helper = require("../helper");
const Msg = require("../models/msg");

const currentSchemaVersion = 1520239200;

const schema = [
// Schema version #1
"CREATE TABLE IF NOT EXISTS options (name TEXT, value TEXT, CONSTRAINT name_unique UNIQUE (name))",
"CREATE TABLE IF NOT EXISTS messages (network TEXT, channel TEXT, time INTEGER, type TEXT, msg TEXT)",
"CREATE INDEX IF NOT EXISTS network_channel ON messages (network, channel)",
"CREATE INDEX IF NOT EXISTS time ON messages (time)",
];

class MessageStorage {
constructor() {
this.isEnabled = false;
}

enable(name) {
const logsPath = path.join(Helper.getHomePath(), "logs");
const sqlitePath = path.join(logsPath, `${name}.sqlite3`);

try {
fsextra.ensureDirSync(logsPath);
} catch (e) {
log.error("Unable to create logs directory", e);

return;
}

this.isEnabled = true;

this.database = new sqlite3.cached.Database(sqlitePath);
this.database.serialize(() => {
schema.forEach((line) => this.database.run(line));

this.database.get("SELECT value FROM options WHERE name = 'schema_version'", (err, row) => {
if (err) {
return log.error(`Failed to retrieve schema version: ${err}`);
}

// New table
if (row === undefined) {
this.database.serialize(() => this.database.run("INSERT INTO options (name, value) VALUES ('schema_version', ?)", currentSchemaVersion));

return;
}

const storedSchemaVersion = parseInt(row.value, 10);

if (storedSchemaVersion === currentSchemaVersion) {
return;
}

if (storedSchemaVersion > currentSchemaVersion) {
return log.error(`sqlite messages schema version is higher than expected (${storedSchemaVersion} > ${currentSchemaVersion}). Is The Lounge out of date?`);
}

log.info(`sqlite messages schema version is out of date (${storedSchemaVersion} < ${currentSchemaVersion}). Running migrations if any.`);

this.database.serialize(() => this.database.run("UPDATE options SET value = ? WHERE name = 'schema_version'", currentSchemaVersion));
});
});
}

index(network, channel, msg) {
if (!this.isEnabled) {
return;
}

const clonedMsg = Object.keys(msg).reduce((newMsg, prop) => {
// id is regenerated when messages are retrieved
// previews are not stored because storage is cleared on lounge restart
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we have a way to re-trigger previews when they are loaded? (i.e. if user never loads older messages, they wouldn't get re-fetched)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We technically can, but I wouldn't look at it because it's not as simple as iterating all links and fetching previews (would need to queue and process with limits).

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Makes sense, I didn't mean in this PR necessarily.

// type and time are stored in a separate column
if (prop !== "id" && prop !== "previews" && prop !== "type" && prop !== "time") {
newMsg[prop] = msg[prop];
}

return newMsg;
}, {});

this.database.serialize(() => this.database.run(
"INSERT INTO messages(network, channel, time, type, msg) VALUES(?, ?, ?, ?, ?)",
network, channel.toLowerCase(), msg.time.getTime(), msg.type, JSON.stringify(clonedMsg)
));
}

/**
* Load messages for given channel on a given network and resolve a promise with loaded messages.
*
* @param Network network - Network object where the channel is
* @param Chan channel - Channel object for which to load messages for
*/
getMessages(network, channel) {
if (!this.isEnabled || Helper.config.maxHistory < 1) {
return Promise.resolve([]);
}

return new Promise((resolve, reject) => {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I found https://github.com/kriasoft/node-sqlite when looking if node-sqlite3 can return promises. No idea if that's an acceptable candidate, but I also appreciated that it has built-in support for migrations!
It seems to be a simple wrapper around node-sqlite3 that might serve us well maybe?

Copy link
Member Author

@xPaw xPaw Mar 4, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That doesn't really solve anything that I haven't solved here already, so I'm not keen on switching. This can be done in a future PR if really needed.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would make the code about promises a tiny bit simpler, but more importantly it would bring support for migrations. I'm still concerned how we're going to deal with this from now on. Doesn't have to be now, but before v3 we need to find a solution that will work for us overtime or we'll regret it 😅

this.database.parallelize(() => this.database.all(
"SELECT msg, type, time FROM messages WHERE network = ? AND channel = ? ORDER BY time DESC LIMIT ?",
[network.uuid, channel.name.toLowerCase(), Helper.config.maxHistory],
(err, rows) => {
if (err) {
return reject(err);
}

resolve(rows.map((row) => {
const msg = JSON.parse(row.msg);
msg.time = row.time;
msg.type = row.type;

return new Msg(msg);
}).reverse());
}
));
});
}
}

module.exports = MessageStorage;
1 change: 1 addition & 0 deletions src/server.js
Original file line number Diff line number Diff line change
Expand Up @@ -306,6 +306,7 @@ function initializeClient(socket, client, token, lastMessage) {
// prevent people from overriding webirc settings
data.ip = null;
data.hostname = null;
data.uuid = null;

client.connect(data);
}
Expand Down
Loading