Add timing to logs, fix issue of silently ignored I/O errors

This commit is contained in:
Marvin W 2019-12-22 19:28:40 +01:00
parent 9ef4dddfdc
commit 1bb75f40d2
No known key found for this signature in database
GPG key ID: 072E9235DB996F2A
5 changed files with 20 additions and 19 deletions

View file

@ -218,13 +218,12 @@ public class MessageProcessor : StreamInteractionModule, Object {
}
while (iq != null) {
debug("MAM: [%s] IN: %s", account.bare_jid.to_string(), iq.stanza.to_string());
string? earliest_id = iq.stanza.get_deep_string_content("urn:xmpp:mam:2:fin", "http://jabber.org/protocol/rsm" + ":set", "first");
if (earliest_id == null) return true;
if (!mam_times[account].has_key(earliest_id)) error("wtf");
debug("MAM: [%s] Update from_id %s\n", account.bare_jid.to_string(), earliest_id);
debug("MAM: [%s] Update from_id %s", account.bare_jid.to_string(), earliest_id);
if (!current_catchup_id.has_key(account)) {
debug("MAM: [%s] We get our first MAM page", account.bare_jid.to_string());
string? latest_id = iq.stanza.get_deep_string_content("urn:xmpp:mam:2:fin", "http://jabber.org/protocol/rsm" + ":set", "last");

View file

@ -26,14 +26,15 @@ public class StanzaWriter {
running = true;
try {
yield output.write_all_async(data, 0, null, null);
SourceFuncWrapper? sfw = queue.pop_head();
if (sfw != null) {
sfw.sfun();
}
} catch (GLib.Error e) {
throw new XmlError.IO(@"IOError in GLib: $(e.message)");
} finally {
running = false;
SourceFuncWrapper? sfw = queue.pop_head();
if (sfw != null) {
sfw.sfun();
} else {
running = false;
}
}
}
}

View file

@ -108,15 +108,15 @@ public class XmppLog {
return false;
}
public void node(string what, StanzaNode node) {
public void node(string what, StanzaNode node, XmppStream stream) {
if (should_log_node(node)) {
stderr.printf("%sXMPP %s [%s]%s\n%s\n", use_ansi ? ANSI_COLOR_WHITE : "", what, ident, use_ansi ? ANSI_COLOR_END : "", use_ansi ? node.to_ansi_string(hide_ns) : node.to_string());
stderr.printf("%sXMPP %s [%s %p %s]%s\n%s\n", use_ansi ? ANSI_COLOR_WHITE : "", what, ident, stream, new DateTime.now_local().to_string(), use_ansi ? ANSI_COLOR_END : "", use_ansi ? node.to_ansi_string(hide_ns) : node.to_string());
}
}
public void str(string what, string str) {
public void str(string what, string str, XmppStream stream) {
if (should_log_str(str)) {
stderr.printf("%sXMPP %s [%s]%s\n%s\n", use_ansi ? ANSI_COLOR_WHITE : "", what, ident, use_ansi ? ANSI_COLOR_END : "", str);
stderr.printf("%sXMPP %s [%s %p %s]%s\n%s\n", use_ansi ? ANSI_COLOR_WHITE : "", what, ident, stream, new DateTime.now_local().to_string(), use_ansi ? ANSI_COLOR_END : "", str);
}
}

View file

@ -81,7 +81,7 @@ public class XmppStream {
if (writer == null || reader == null || stream == null) {
throw new IOStreamError.DISCONNECT("trying to disconnect, but no stream open");
}
log.str("OUT", "</stream:stream>");
log.str("OUT", "</stream:stream>", this);
yield writer.write("</stream:stream>");
reader.cancel();
yield stream.close_async();
@ -107,22 +107,25 @@ public class XmppStream {
if (reader == null) throw new IOStreamError.READ("trying to read, but no stream open");
try {
StanzaNode node = yield ((!)reader).read_node();
log.node("IN", node);
log.node("IN", node, this);
return node;
} catch (XmlError e) {
throw new IOStreamError.READ(e.message);
}
}
[Version (deprecated = true, deprecated_since = "0.1", replacement = "write_async")]
public void write(StanzaNode node) {
write_async.begin(node);
write_async.begin(node, (obj, res) => {
write_async.end(res);
});
}
public async void write_async(StanzaNode node) throws IOStreamError {
StanzaWriter? writer = this.writer;
if (writer == null) throw new IOStreamError.WRITE("trying to write, but no stream open");
try {
log.node("OUT", node);
log.node("OUT", node, this);
yield ((!)writer).write_node(node);
} catch (XmlError e) {
throw new IOStreamError.WRITE(e.message);
@ -201,7 +204,7 @@ public class XmppStream {
.put_attribute("xmlns", "jabber:client")
.put_attribute("stream", "http://etherx.jabber.org/streams", XMLNS_URI);
outs.has_nodes = true;
log.node("OUT ROOT", outs);
log.node("OUT ROOT", outs, this);
write(outs);
received_root_node(this, yield read_root());
}
@ -293,7 +296,7 @@ public class XmppStream {
if (reader == null) throw new IOStreamError.READ("trying to read, but no stream open");
try {
StanzaNode node = yield ((!)reader).read_root_node();
log.node("IN ROOT", node);
log.node("IN ROOT", node, this);
return node;
} catch (XmlError.TLS e) {
throw new IOStreamError.TLS(e.message);

View file

@ -60,8 +60,6 @@ public class Module : XmppStreamModule {
query_node.put_node(create_set_rsm_node(end_id));
Iq.Stanza iq = new Iq.Stanza.set(query_node);
debug(@"OUT INIT: %s", iq.stanza.to_string());
Iq.Stanza? result_iq = null;
stream.get_module(Iq.Module.IDENTITY).send_iq(stream, iq, (stream, iq) => {
result_iq = iq;