From a665293268b9dc97739681eeaa2f69649841a5e4 Mon Sep 17 00:00:00 2001 From: projectmoon Date: Mon, 17 May 2021 23:12:27 +0000 Subject: [PATCH] Fix recording of room users, better logging. - Fix constraint violations when recording users in rooms (migration fix). - Switched to tracing_subscriber to get log events from matrix SDK. - Remove "Applying migration" messages, and rely on refinery to log instead. - Log when an outgoing error is encountered. --- Cargo.lock | 201 ++++++++++++------ Cargo.toml | 2 +- src/bin/dicebot.rs | 15 +- src/bot.rs | 13 +- src/logic.rs | 2 - src/matrix.rs | 2 +- src/migrator/migrations/V1__variables.rs | 2 - .../{V2__rooms.rs => V2__room_info.rs} | 15 -- src/migrator/migrations/V3__dbstate.rs | 2 - src/migrator/migrations/V4__room_events.rs | 18 +- src/migrator/migrations/V5__room_users.rs | 22 ++ 11 files changed, 179 insertions(+), 115 deletions(-) rename src/migrator/migrations/{V2__rooms.rs => V2__room_info.rs} (55%) create mode 100644 src/migrator/migrations/V5__room_users.rs diff --git a/Cargo.lock b/Cargo.lock index 2c5c2a1..95caf01 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -92,6 +92,15 @@ dependencies = [ "memchr", ] +[[package]] +name = "ansi_term" +version = "0.12.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d52a9bb7ec0cf484c551830a7ce27bd20d67eac647e1befb56b0be4ee39a55d2" +dependencies = [ + "winapi", +] + [[package]] name = "arrayvec" version = "0.5.2" @@ -133,17 +142,6 @@ dependencies = [ "autocfg", ] -[[package]] -name = "atty" -version = "0.2.14" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "d9b39be18770d11421cdb1b9947a45dd3f37e93092cbf377614828a319d5fee8" -dependencies = [ - "hermit-abi", - "libc", - "winapi", -] - [[package]] name = "autocfg" version = "1.0.1" @@ -505,19 +503,6 @@ dependencies = [ "cfg-if", ] -[[package]] -name = "env_logger" -version = "0.8.3" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "17392a012ea30ef05a610aa97dfb49496e71c9f676b27879922ea5bdf60d9d3f" -dependencies = [ - "atty", - "humantime", - "log", - "regex", - "termcolor", -] - [[package]] name = "fallible-iterator" version = "0.2.0" @@ -896,12 +881,6 @@ version = "1.0.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "05842d0d43232b23ccb7060ecb0f0626922c21f30012e97b767b30afd4a5d4b9" -[[package]] -name = "humantime" -version = "2.1.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" - [[package]] name = "hyper" version = "0.14.7" @@ -1114,6 +1093,15 @@ dependencies = [ "xml5ever", ] +[[package]] +name = "matchers" +version = "0.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f099785f7595cc4b4553a174ce30dd7589ef93391ff414dbb67f62392b9e0ce1" +dependencies = [ + "regex-automata", +] + [[package]] name = "matches" version = "0.1.8" @@ -1123,7 +1111,7 @@ checksum = "7ffc5c5338469d4d3ea17d269fa8ea3512ad247247c30bd2df69e68309ed0a08" [[package]] name = "matrix-sdk" version = "0.2.0" -source = "git+https://github.com/matrix-org/matrix-rust-sdk?branch=master#ffea84b64aa172b9b153a76588f4f609bf15c441" +source = "git+https://github.com/matrix-org/matrix-rust-sdk?branch=master#cd77441d1bf8318ecf4cc9e1886696558ea6ed7b" dependencies = [ "backoff", "bytes", @@ -1147,7 +1135,7 @@ dependencies = [ [[package]] name = "matrix-sdk-base" version = "0.2.0" -source = "git+https://github.com/matrix-org/matrix-rust-sdk?branch=master#ffea84b64aa172b9b153a76588f4f609bf15c441" +source = "git+https://github.com/matrix-org/matrix-rust-sdk?branch=master#cd77441d1bf8318ecf4cc9e1886696558ea6ed7b" dependencies = [ "chacha20poly1305", "dashmap", @@ -1170,7 +1158,7 @@ dependencies = [ [[package]] name = "matrix-sdk-common" version = "0.2.0" -source = "git+https://github.com/matrix-org/matrix-rust-sdk?branch=master#ffea84b64aa172b9b153a76588f4f609bf15c441" +source = "git+https://github.com/matrix-org/matrix-rust-sdk?branch=master#cd77441d1bf8318ecf4cc9e1886696558ea6ed7b" dependencies = [ "async-trait", "futures", @@ -1186,7 +1174,7 @@ dependencies = [ [[package]] name = "matrix-sdk-crypto" version = "0.2.0" -source = "git+https://github.com/matrix-org/matrix-rust-sdk?branch=master#ffea84b64aa172b9b153a76588f4f609bf15c441" +source = "git+https://github.com/matrix-org/matrix-rust-sdk?branch=master#cd77441d1bf8318ecf4cc9e1886696558ea6ed7b" dependencies = [ "aes-ctr", "aes-gcm", @@ -1793,6 +1781,16 @@ dependencies = [ "regex-syntax", ] +[[package]] +name = "regex-automata" +version = "0.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ae1ded71d66a4a97f5e961fd0cb25a5f366a42a41570d16a763a69c092c26ae4" +dependencies = [ + "byteorder", + "regex-syntax", +] + [[package]] name = "regex-syntax" version = "0.6.25" @@ -1844,8 +1842,9 @@ dependencies = [ [[package]] name = "ruma" -version = "0.0.3" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4b4014a3def1ed10e7fa0fe28fec48418f2deb6135e7f5fe15901ba1302b581c" dependencies = [ "assign", "js_int", @@ -1860,8 +1859,9 @@ dependencies = [ [[package]] name = "ruma-api" -version = "0.17.0-alpha.4" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.17.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "51df85b3e2c4097abc60919864502083def5c3b12982b0c46f6431e5b1e1476d" dependencies = [ "bytes", "http", @@ -1876,8 +1876,9 @@ dependencies = [ [[package]] name = "ruma-api-macros" -version = "0.17.0-alpha.4" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.17.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fe79932728de6a753163f4f30acfd70ebe4355c35fc638edb3f47c7cf47ab128" dependencies = [ "proc-macro-crate", "proc-macro2", @@ -1887,8 +1888,9 @@ dependencies = [ [[package]] name = "ruma-client-api" -version = "0.10.0-alpha.3" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.10.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fda53002660ebdf6eca81102bf4362d0f9234a4d3f7a3e5f9878ed7c1f133843" dependencies = [ "assign", "bytes", @@ -1907,8 +1909,9 @@ dependencies = [ [[package]] name = "ruma-common" -version = "0.5.0" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.5.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c87e1a95f3625cae17772e98b3479059e7aa18593fb623bcff498d32d399d956" dependencies = [ "indexmap", "js_int", @@ -1922,8 +1925,9 @@ dependencies = [ [[package]] name = "ruma-events" -version = "0.22.0-alpha.3" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.22.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "15c222b0f008461b00b039e76319c3184633346605b8201b24f54a6be99cbd98" dependencies = [ "indoc", "js_int", @@ -1937,8 +1941,9 @@ dependencies = [ [[package]] name = "ruma-events-macros" -version = "0.22.0-alpha.3" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.22.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "270df7148218b4d45d11bc1621c4ce5da8571abaf2db3f407a4b0f983a48625c" dependencies = [ "proc-macro-crate", "proc-macro2", @@ -1948,8 +1953,9 @@ dependencies = [ [[package]] name = "ruma-federation-api" -version = "0.1.0-alpha.2" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "40fe42fd5951c688b5c7b0c32ed74d973d21c33ba31f9d64d40bf4f98c01eb48" dependencies = [ "js_int", "ruma-api", @@ -1963,8 +1969,9 @@ dependencies = [ [[package]] name = "ruma-identifiers" -version = "0.19.0" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.19.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4b63396866eab1d0dafe5bd3c1af2e16f1f71a725fcc89a3e3f42572bc20c65a" dependencies = [ "paste", "ruma-identifiers-macros", @@ -1976,8 +1983,9 @@ dependencies = [ [[package]] name = "ruma-identifiers-macros" -version = "0.19.0" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.19.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a77e9bf8fd334e944d40f041155d4950da75a9b64cd05046ffc8ea670ad4ad12" dependencies = [ "quote", "ruma-identifiers-validation", @@ -1987,12 +1995,14 @@ dependencies = [ [[package]] name = "ruma-identifiers-validation" version = "0.3.0" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ecb664a32ba1cccf0d5cec34bef6bfccc042b54b8b5f9610729a128fcdf569a5" [[package]] name = "ruma-serde" -version = "0.3.1" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c888d69db1d5f134cbce7101f5610f1802966f359646ff48dbaf0f433d7bbd9f" dependencies = [ "bytes", "form_urlencoded", @@ -2005,8 +2015,9 @@ dependencies = [ [[package]] name = "ruma-serde-macros" -version = "0.3.1" -source = "git+https://github.com/ruma/ruma?rev=e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6#e1ab817e0bef78cb8241d6d3c1ced7d6b414c7f6" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "be418f3ee1593ebf1522d9ace1b1de0455bbcdd69c5d584c00d41e7717f8d0af" dependencies = [ "proc-macro-crate", "proc-macro2", @@ -2176,6 +2187,15 @@ dependencies = [ "opaque-debug", ] +[[package]] +name = "sharded-slab" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "79c719719ee05df97490f80a45acfc99e5a30ce98a1e4fb67aee422745ae14e3" +dependencies = [ + "lazy_static", +] + [[package]] name = "signal-hook-registry" version = "1.3.0" @@ -2497,7 +2517,6 @@ dependencies = [ "byteorder", "combine", "dirs", - "env_logger", "futures", "html2text", "indoc", @@ -2516,19 +2535,11 @@ dependencies = [ "thiserror", "tokio", "toml", + "tracing-subscriber", "url", "zerocopy", ] -[[package]] -name = "termcolor" -version = "1.1.2" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "2dfed899f0eb03f32ee8c6a0aabdb8a7949659e3466561fc0adf54e26d88c5f4" -dependencies = [ - "winapi-util", -] - [[package]] name = "thiserror" version = "1.0.24" @@ -2549,6 +2560,15 @@ dependencies = [ "syn", ] +[[package]] +name = "thread_local" +version = "1.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8018d24e04c95ac8790716a5987d0fec4f8b27249ffa0f7d33f1369bdfb88cbd" +dependencies = [ + "once_cell", +] + [[package]] name = "time" version = "0.1.43" @@ -2735,6 +2755,49 @@ dependencies = [ "tracing", ] +[[package]] +name = "tracing-log" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a6923477a48e41c1951f1999ef8bb5a3023eb723ceadafe78ffb65dc366761e3" +dependencies = [ + "lazy_static", + "log", + "tracing-core", +] + +[[package]] +name = "tracing-serde" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fb65ea441fbb84f9f6748fd496cf7f63ec9af5bca94dd86456978d055e8eb28b" +dependencies = [ + "serde", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.2.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "aa5553bf0883ba7c9cbe493b085c29926bd41b66afc31ff72cf17ff4fb60dcd5" +dependencies = [ + "ansi_term", + "chrono", + "lazy_static", + "matchers", + "regex", + "serde", + "serde_json", + "sharded-slab", + "smallvec", + "thread_local", + "tracing", + "tracing-core", + "tracing-log", + "tracing-serde", +] + [[package]] name = "try-lock" version = "0.2.3" diff --git a/Cargo.toml b/Cargo.toml index 93eb562..88de99b 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -16,7 +16,7 @@ path = "src/migrate_cli.rs" [dependencies] log = "0.4" -env_logger = "0.8" +tracing-subscriber = "0.2" toml = "0.5" nom = "5" rand = "0.8" diff --git a/src/bin/dicebot.rs b/src/bin/dicebot.rs index d4ee65f..8be23db 100644 --- a/src/bin/dicebot.rs +++ b/src/bin/dicebot.rs @@ -1,7 +1,7 @@ //Needed for nested Result handling from tokio. Probably can go away after 1.47.0. #![type_length_limit = "7605144"] -use env_logger::Env; use log::error; +use std::env; use std::sync::{Arc, RwLock}; use tenebrous_dicebot::bot::DiceBot; use tenebrous_dicebot::config::*; @@ -9,13 +9,18 @@ use tenebrous_dicebot::db::sqlite::Database; use tenebrous_dicebot::error::BotError; use tenebrous_dicebot::migrator; use tenebrous_dicebot::state::DiceBotState; +use tracing_subscriber::filter::EnvFilter; #[tokio::main] async fn main() { - env_logger::Builder::from_env( - Env::default().default_filter_or("tenebrous_dicebot=info,dicebot=info"), - ) - .init(); + let filter = if env::var("RUST_LOG").is_ok() { + EnvFilter::from_default_env() + } else { + EnvFilter::new("tenebrous_dicebot=info,dicebot=info,refinery=info") + }; + + tracing_subscriber::fmt().with_env_filter(filter).init(); + match run().await { Ok(_) => (), Err(e) => error!("Error: {}", e), diff --git a/src/bot.rs b/src/bot.rs index a208882..58b9b20 100644 --- a/src/bot.rs +++ b/src/bot.rs @@ -8,7 +8,7 @@ use crate::matrix; use crate::state::DiceBotState; use dirs; use futures::stream::{self, StreamExt}; -use log::info; +use log::{error, info}; use matrix_sdk::{self, identifiers::EventId, room::Joined, Client, ClientConfig, SyncSettings}; use std::clone::Clone; use std::path::PathBuf; @@ -62,6 +62,13 @@ async fn handle_single_result( room: &Joined, event_id: EventId, ) { + if cmd_result.is_err() { + error!( + "Command execution error: {}", + cmd_result.as_ref().err().unwrap() + ); + } + let html = cmd_result.message_html(respond_to); matrix::send_message(client, room.room_id(), &html, Some(event_id)).await; } @@ -87,6 +94,10 @@ async fn handle_multiple_results( }) .collect(); + for result in errors.iter() { + error!("Command execution error: '{}' - {}", result.0, result.1); + } + let message = if errors.len() == 0 { format!("{}: Executed {} commands", respond_to, results.len()) } else { diff --git a/src/logic.rs b/src/logic.rs index 5be59a6..7b67ce0 100644 --- a/src/logic.rs +++ b/src/logic.rs @@ -33,8 +33,6 @@ pub async fn record_room_information( .into_iter() .filter(|username| username != our_username); - println!("Users to add to room: {:?}", filtered_usernames); - // Async collect into vec of results, then use into_iter of result // to go to from Result> to just Result<()>. Easier than // attempting to async-collect our way to a single Result<()>. diff --git a/src/matrix.rs b/src/matrix.rs index 7ff73c4..6c8e7d8 100644 --- a/src/matrix.rs +++ b/src/matrix.rs @@ -53,7 +53,7 @@ pub async fn send_message( )); content.relates_to = reply_to.map(|event_id| Relation::Reply { - in_reply_to: InReplyTo { event_id }, + in_reply_to: InReplyTo::new(event_id), }); let content = AnyMessageEventContent::RoomMessage(content); diff --git a/src/migrator/migrations/V1__variables.rs b/src/migrator/migrations/V1__variables.rs index ec8f063..a494bc7 100644 --- a/src/migrator/migrations/V1__variables.rs +++ b/src/migrator/migrations/V1__variables.rs @@ -1,10 +1,8 @@ use barrel::backend::Sqlite; use barrel::{types, Migration}; -use log::info; pub fn migration() -> String { let mut m = Migration::new(); - info!("Applying migration: {}", file!()); m.create_table("user_variables", |t| { t.add_column("room_id", types::text()); diff --git a/src/migrator/migrations/V2__rooms.rs b/src/migrator/migrations/V2__room_info.rs similarity index 55% rename from src/migrator/migrations/V2__rooms.rs rename to src/migrator/migrations/V2__room_info.rs index 5568a01..fb6ebb2 100644 --- a/src/migrator/migrations/V2__rooms.rs +++ b/src/migrator/migrations/V2__room_info.rs @@ -1,21 +1,12 @@ use barrel::backend::Sqlite; use barrel::{types, types::Type, Migration}; -use log::info; fn primary_uuid() -> Type { types::text().unique(true).primary(true).nullable(false) } -fn autoincrement_int() -> Type { - types::integer() - .increments(true) - .unique(true) - .primary(false) -} - pub fn migration() -> String { let mut m = Migration::new(); - info!("Applying migration: {}", file!()); //Table for basic room information: room ID, room name m.create_table("room_info", move |t| { @@ -23,11 +14,5 @@ pub fn migration() -> String { t.add_column("room_name", types::text()); }); - //Table of users in rooms. - m.create_table("room_users", move |t| { - t.add_column("room_id", autoincrement_int()); - t.add_column("username", types::text()); - }); - m.make::() } diff --git a/src/migrator/migrations/V3__dbstate.rs b/src/migrator/migrations/V3__dbstate.rs index 0ae82c2..3bb25c0 100644 --- a/src/migrator/migrations/V3__dbstate.rs +++ b/src/migrator/migrations/V3__dbstate.rs @@ -1,10 +1,8 @@ use barrel::backend::Sqlite; use barrel::{types, Migration}; -use log::info; pub fn migration() -> String { let mut m = Migration::new(); - info!("Applying migration: {}", file!()); //Basic state table with only device ID for now. Uses only one row. m.create_table("bot_state", move |t| { diff --git a/src/migrator/migrations/V4__room_events.rs b/src/migrator/migrations/V4__room_events.rs index d9d487b..8657a98 100644 --- a/src/migrator/migrations/V4__room_events.rs +++ b/src/migrator/migrations/V4__room_events.rs @@ -1,21 +1,7 @@ use barrel::backend::Sqlite; use barrel::{types, types::Type, Migration}; -use log::info; - -fn primary_uuid() -> Type { - types::text().unique(true).nullable(false) -} - -fn autoincrement_int() -> Type { - types::integer() - .increments(true) - .unique(true) - .primary(false) -} - pub fn migration() -> String { let mut m = Migration::new(); - info!("Applying migration: {}", file!()); //Table of room ID, event ID, event timestamp m.create_table("room_events", move |t| { @@ -32,7 +18,5 @@ pub fn migration() -> String { res.pop(); } - let x = format!("{}, PRIMARY KEY (room_id, event_id));", res); - println!("{}", x); - x + format!("{}, PRIMARY KEY (room_id, event_id));", res) } diff --git a/src/migrator/migrations/V5__room_users.rs b/src/migrator/migrations/V5__room_users.rs new file mode 100644 index 0000000..eedec4d --- /dev/null +++ b/src/migrator/migrations/V5__room_users.rs @@ -0,0 +1,22 @@ +use barrel::backend::Sqlite; +use barrel::{types, types::Type, Migration}; + +pub fn migration() -> String { + let mut m = Migration::new(); + + //Table of users in rooms. + m.create_table("room_users", move |t| { + t.add_column("room_id", types::text()); + t.add_column("username", types::text()); + }); + + let mut res = m.make::(); + + //This is a hack that gives us a composite primary key. + if res.ends_with(");") { + res.pop(); + res.pop(); + } + + format!("{}, PRIMARY KEY (room_id, username));", res) +}