Enable logging in tests and fix error log flooding from mock chain ru…

…ntime

.github/workflows/rust.yml

@@ -67,7 +67,7 @@ jobs:
       - uses: actions-rs/cargo@v1
         with:
           command: test
-          args: --all-features --no-fail-fast
+          args: --all-features --no-fail-fast -- --nocapture
 
   # test-coverage:
   #   runs-on: ubuntu-latest

.gitignore

@@ -20,3 +20,5 @@ data
 # Ignore Python artifacts
 .mypy_cache/
 __pycache__/
+
+.modelator

modules/Cargo.toml

@@ -48,6 +48,9 @@ version = "=0.19.0"
 optional = true
 
 [dev-dependencies]
+env_logger = "0.8.3"
+tracing-subscriber = "0.2.18"
+test-env-log = { version = "0.2.7", features = ["trace"] }
 modelator = { git = "https://github.com/informalsystems/modelator", rev = "99f656fa8b3cf46a2aa0b6513e4e140d1778c4bd" }
 tendermint-rpc = { version = "=0.19.0", features = ["http-client", "websocket-client"] }
 tendermint-testgen = { version = "=0.19.0" } # Needed for generating (synthetic) light blocks.

modules/src/ics02_client/client_state.rs

@@ -209,6 +209,7 @@ impl From<IdentifiedAnyClientState> for IdentifiedClientState {
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use prost_types::Any;
 

modules/src/ics02_client/client_type.rs

@@ -49,6 +49,7 @@ impl std::str::FromStr for ClientType {
 #[cfg(test)]
 mod tests {
     use std::str::FromStr;
+    use test_env_log::test;
 
     use super::ClientType;
 

modules/src/ics02_client/handler/create_client.rs

@@ -59,6 +59,7 @@ pub fn process(
 mod tests {
     use std::convert::TryInto;
     use std::time::Duration;
+    use test_env_log::test;
 
     use tendermint::trust_threshold::TrustThresholdFraction as TrustThreshold;
 

modules/src/ics02_client/handler/update_client.rs

@@ -74,6 +74,7 @@ pub fn process(
 #[cfg(test)]
 mod tests {
     use std::str::FromStr;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::handler::HandlerOutput;

modules/src/ics02_client/msgs/create_client.rs

@@ -102,6 +102,7 @@ impl From<MsgCreateAnyClient> for RawMsgCreateClient {
 #[cfg(test)]
 mod tests {
     use std::convert::{TryFrom, TryInto};
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::client::v1::MsgCreateClient;
 

modules/src/ics02_client/msgs/update_client.rs

@@ -78,6 +78,7 @@ impl From<MsgUpdateAnyClient> for RawMsgUpdateClient {
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::client::v1::MsgUpdateClient;
 

modules/src/ics03_connection/handler/conn_open_ack.rs

@@ -104,6 +104,7 @@ pub(crate) fn process(
 mod tests {
     use std::convert::TryFrom;
     use std::str::FromStr;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::ics03_connection::connection::{ConnectionEnd, Counterparty, State};

modules/src/ics03_connection/handler/conn_open_confirm.rs

@@ -78,6 +78,7 @@ pub(crate) fn process(
 mod tests {
     use std::convert::TryFrom;
     use std::str::FromStr;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::ics03_connection::connection::{ConnectionEnd, Counterparty, State};

modules/src/ics03_connection/handler/conn_open_init.rs

@@ -56,6 +56,7 @@ pub(crate) fn process(
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::ics03_connection::connection::State;

modules/src/ics03_connection/handler/conn_open_try.rs

@@ -122,6 +122,7 @@ pub(crate) fn process(
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::ics03_connection::connection::State;

modules/src/ics03_connection/msgs/conn_open_ack.rs

@@ -198,6 +198,7 @@ pub mod test_util {
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::client::v1::Height;
     use ibc_proto::ibc::core::connection::v1::MsgConnectionOpenAck as RawMsgConnectionOpenAck;

modules/src/ics03_connection/msgs/conn_open_confirm.rs

@@ -104,6 +104,7 @@ pub mod test_util {
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::client::v1::Height;
     use ibc_proto::ibc::core::connection::v1::MsgConnectionOpenConfirm as RawMsgConnectionOpenConfirm;

modules/src/ics03_connection/msgs/conn_open_init.rs

@@ -122,6 +122,7 @@ pub mod test_util {
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::connection::v1::Counterparty as RawCounterparty;
     use ibc_proto::ibc::core::connection::v1::MsgConnectionOpenInit as RawMsgConnectionOpenInit;

modules/src/ics03_connection/msgs/conn_open_try.rs

@@ -268,6 +268,7 @@ pub mod test_util {
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::client::v1::Height;
     use ibc_proto::ibc::core::connection::v1::Counterparty as RawCounterparty;

modules/src/ics03_connection/version.rs

@@ -95,6 +95,7 @@ pub fn pick_version(
 #[cfg(test)]
 mod tests {
     use std::convert::{TryFrom, TryInto};
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::connection::v1::Version as RawVersion;
 

modules/src/ics04_channel/channel.rs

@@ -468,6 +468,7 @@ pub mod test_util {
 mod tests {
     use std::convert::TryFrom;
     use std::str::FromStr;
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::channel::v1::Channel as RawChannel;
 

modules/src/ics04_channel/handler/acknowledgement.rs

@@ -143,6 +143,7 @@ mod tests {
     use crate::ics24_host::identifier::{ChannelId, ClientId, ConnectionId, PortId};
     use crate::mock::context::MockContext;
     use crate::timestamp::ZERO_DURATION;
+    use test_env_log::test;
 
     use std::convert::TryFrom;
 

modules/src/ics04_channel/handler/chan_open_ack.rs

@@ -103,6 +103,7 @@ pub(crate) fn process(
 mod tests {
     use std::convert::TryFrom;
     use std::str::FromStr;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::ics03_connection::connection::ConnectionEnd;

modules/src/ics04_channel/handler/chan_open_confirm.rs

@@ -99,6 +99,7 @@ pub(crate) fn process(
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::ics02_client::client_type::ClientType;

modules/src/ics04_channel/handler/chan_open_init.rs

@@ -86,6 +86,7 @@ pub(crate) fn process(
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::ics03_connection::connection::ConnectionEnd;

modules/src/ics04_channel/handler/chan_open_try.rs

@@ -155,6 +155,7 @@ pub(crate) fn process(
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::ics02_client::client_type::ClientType;

modules/src/ics04_channel/handler/recv_packet.rs

@@ -136,6 +136,7 @@ pub fn process(ctx: &dyn ChannelReader, msg: MsgRecvPacket) -> HandlerResult<Pac
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use crate::ics03_connection::connection::ConnectionEnd;
     use crate::ics03_connection::connection::Counterparty as ConnectionCounterparty;

modules/src/ics04_channel/handler/send_packet.rs

@@ -117,6 +117,7 @@ pub fn send_packet(ctx: &dyn ChannelReader, packet: Packet) -> HandlerResult<Pac
 #[cfg(test)]
 mod tests {
     use std::convert::TryInto;
+    use test_env_log::test;
 
     use crate::events::IbcEvent;
     use crate::ics02_client::height::Height;

modules/src/ics04_channel/handler/timeout.rs

@@ -160,6 +160,7 @@ mod tests {
     use crate::mock::context::MockContext;
 
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     #[test]
     fn timeout_packet_processing() {

modules/src/ics04_channel/handler/timeout_on_close.rs

@@ -156,6 +156,7 @@ mod tests {
     use crate::mock::context::MockContext;
 
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     #[test]
     fn timeout_on_close_packet_processing() {

modules/src/ics04_channel/handler/write_acknowledgement.rs

@@ -82,6 +82,7 @@ pub fn process(
 #[cfg(test)]
 mod tests {
     use std::convert::TryInto;
+    use test_env_log::test;
 
     use crate::ics02_client::height::Height;
     use crate::ics03_connection::connection::ConnectionEnd;

modules/src/ics04_channel/msgs/acknowledgement.rs

@@ -131,6 +131,7 @@ pub mod test_util {
 #[cfg(test)]
 mod test {
     use std::convert::TryInto;
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::channel::v1::MsgAcknowledgement as RawMsgAcknowledgement;
 

modules/src/ics04_channel/msgs/chan_close_init.rs

@@ -102,6 +102,7 @@ pub mod test_util {
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::channel::v1::MsgChannelCloseInit as RawMsgChannelCloseInit;
 

modules/src/ics04_channel/msgs/chan_open_ack.rs

@@ -159,6 +159,7 @@ pub mod test_util {
 #[cfg(test)]
 mod tests {
     use ibc_proto::ibc::core::channel::v1::MsgChannelOpenAck as RawMsgChannelOpenAck;
+    use test_env_log::test;
 
     use crate::ics04_channel::msgs::chan_open_ack::test_util::get_dummy_raw_msg_chan_open_ack;
     use crate::ics04_channel::msgs::chan_open_ack::MsgChannelOpenAck;

modules/src/ics04_channel/msgs/chan_open_confirm.rs

@@ -132,6 +132,7 @@ pub mod test_util {
 #[cfg(test)]
 mod tests {
     use ibc_proto::ibc::core::channel::v1::MsgChannelOpenConfirm as RawMsgChannelOpenConfirm;
+    use test_env_log::test;
 
     use crate::ics04_channel::msgs::chan_open_confirm::test_util::get_dummy_raw_msg_chan_open_confirm;
     use crate::ics04_channel::msgs::chan_open_confirm::MsgChannelOpenConfirm;

modules/src/ics04_channel/msgs/chan_open_init.rs

@@ -105,6 +105,7 @@ mod tests {
     use crate::ics04_channel::msgs::chan_open_init::MsgChannelOpenInit;
     use ibc_proto::ibc::core::channel::v1::MsgChannelOpenInit as RawMsgChannelOpenInit;
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     #[test]
     fn channel_open_init_from_raw() {

modules/src/ics04_channel/msgs/chan_open_try.rs

@@ -177,6 +177,7 @@ mod tests {
     use ibc_proto::ibc::core::channel::v1::MsgChannelOpenTry as RawMsgChannelOpenTry;
     use ibc_proto::ibc::core::client::v1::Height;
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     #[test]
     fn channel_open_try_from_raw() {

modules/src/ics04_channel/msgs/recv_packet.rs

@@ -113,6 +113,7 @@ pub mod test_util {
 #[cfg(test)]
 mod test {
     use std::convert::{TryFrom, TryInto};
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::channel::v1::MsgRecvPacket as RawMsgRecvPacket;
 

modules/src/ics04_channel/msgs/timeout.rs

@@ -125,6 +125,7 @@ pub mod test_util {
 #[cfg(test)]
 mod test {
     use std::convert::{TryFrom, TryInto};
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::channel::v1::MsgTimeout as RawMsgTimeout;
 

modules/src/ics04_channel/packet.rs

@@ -253,6 +253,7 @@ pub mod test_utils {
 #[cfg(test)]
 mod tests {
     use std::convert::TryFrom;
+    use test_env_log::test;
 
     use ibc_proto::ibc::core::channel::v1::Packet as RawPacket;
 

modules/src/ics07_tendermint/client_state.rs

@@ -235,6 +235,7 @@ impl From<ClientState> for RawClientState {
 #[cfg(test)]
 mod tests {
     use std::time::Duration;
+    use test_env_log::test;
 
     use tendermint::trust_threshold::TrustThresholdFraction as TrustThreshold;
     use tendermint_rpc::endpoint::abci_query::AbciQuery;