Use ctor crate to setup/teardown tests

Use TestLogger for all tests. Now it delegates to env_logger too

Signed-off-by: Martin Tzvetanov Grigorov <mgrigorov@apache.org>

diff --git a/lang/rust/Cargo.toml b/lang/rust/Cargo.toml
index 9f188c0656ea69bc4c753f8f865b0afe97a4911b..527bfb3fe2cfbc72338add87d936812469bd6d6f 100644 (file)
--- a/lang/rust/Cargo.toml
+++ b/lang/rust/Cargo.toml
@@ -17,6 +17,7 @@
 
 [workspace]
 members = [
+    "avro_test_helper",
     "avro",
     "avro_derive"
 ]

diff --git a/lang/rust/avro/Cargo.toml b/lang/rust/avro/Cargo.toml
index 268cdfb2d19e841ff71e34810de7f21ad337b1ea..389c41dbadb79df69c44427161da17283819eec6 100644 (file)
--- a/lang/rust/avro/Cargo.toml
+++ b/lang/rust/avro/Cargo.toml
@@ -77,10 +77,9 @@ zstd = { default-features = false, version = "0.11.1+zstd.1.5.2", optional = tru
 apache-avro-derive = { default-features = false, version= "0.14.0", path = "../avro_derive", optional = true }
 
 [dev-dependencies]
-md-5 = "0.10.1"
-sha2 = "0.10.2"
-criterion = "0.3.5"
 anyhow = "1.0.56"
+apache-avro-test-helper = { version= "0.1.0", path = "../avro_test_helper" }
+criterion = "0.3.5"
 hex-literal = "0.3.4"
-env_logger = "0.9.0"
-ref_thread_local = "0.1.1"
+md-5 = "0.10.1"
+sha2 = "0.10.2"

diff --git a/lang/rust/avro/src/types.rs b/lang/rust/avro/src/types.rs
index 78b000552e996907be713a3f5c0fe7347545715d..93045ee65c279157302628c19f8c5cd2168cf6c3 100644 (file)
--- a/lang/rust/avro/src/types.rs
+++ b/lang/rust/avro/src/types.rs
@@ -938,48 +938,9 @@ mod tests {
         schema::{Name, RecordField, RecordFieldOrder, Schema, UnionSchema},
         types::Value,
     };
-    use log::{Level, LevelFilter, Metadata};
+    use apache_avro_test_helper::logger::assert_logged;
     use uuid::Uuid;
 
-    use ref_thread_local::{ref_thread_local, RefThreadLocal};
-
-    ref_thread_local! {
-        // The unit tests run in parallel
-        // We need to keep the log messages in a thread-local variable
-        // and clear them after assertion
-        static managed LOG_MESSAGES: Vec<String> = Vec::new();
-    }
-
-    struct TestLogger;
-
-    impl log::Log for TestLogger {
-        fn enabled(&self, metadata: &Metadata) -> bool {
-            metadata.level() <= Level::Error
-        }
-
-        fn log(&self, record: &log::Record) {
-            if self.enabled(record.metadata()) {
-                let mut msgs = LOG_MESSAGES.borrow_mut();
-                msgs.push(format!("{}", record.args()));
-            }
-        }
-
-        fn flush(&self) {}
-    }
-
-    static TEST_LOGGER: TestLogger = TestLogger;
-
-    fn init() {
-        let _ = log::set_logger(&TEST_LOGGER);
-        log::set_max_level(LevelFilter::Info);
-    }
-
-    fn assert_log_message(expected_message: &str) {
-        let mut msgs = LOG_MESSAGES.borrow_mut();
-        assert_eq!(msgs.pop().unwrap(), expected_message);
-        msgs.clear();
-    }
-
     #[test]
     fn validate() {
         let value_schema_valid = vec![
@@ -1120,8 +1081,6 @@ mod tests {
 
     #[test]
     fn validate_fixed() {
-        init();
-
         let schema = Schema::Fixed {
             size: 4,
             name: Name::new("some_fixed").unwrap(),
@@ -1132,7 +1091,7 @@ mod tests {
         assert!(Value::Fixed(4, vec![0, 0, 0, 0]).validate(&schema));
         let value = Value::Fixed(5, vec![0, 0, 0, 0, 0]);
         assert!(!value.validate(&schema));
-        assert_log_message(
+        assert_logged(
             format!(
                 "Invalid value: {:?} for schema: {:?}. Reason: {}",
                 value, schema, "The value's size (5) is different than the schema's size (4)"
@@ -1143,7 +1102,7 @@ mod tests {
         assert!(Value::Bytes(vec![0, 0, 0, 0]).validate(&schema));
         let value = Value::Bytes(vec![0, 0, 0, 0, 0]);
         assert!(!value.validate(&schema));
-        assert_log_message(
+        assert_logged(
             format!(
                 "Invalid value: {:?} for schema: {:?}. Reason: {}",
                 value, schema, "The bytes' length (5) is different than the schema's size (4)"
@@ -1154,8 +1113,6 @@ mod tests {
 
     #[test]
     fn validate_enum() {
-        init();
-
         let schema = Schema::Enum {
             name: Name::new("some_enum").unwrap(),
             aliases: None,
@@ -1173,7 +1130,7 @@ mod tests {
 
         let value = Value::Enum(1, "spades".to_string());
         assert!(!value.validate(&schema));
-        assert_log_message(
+        assert_logged(
             format!(
                 "Invalid value: {:?} for schema: {:?}. Reason: {}",
                 value, schema, "Symbol 'spades' is not at position '1'"
@@ -1183,7 +1140,7 @@ mod tests {
 
         let value = Value::Enum(1000, "spades".to_string());
         assert!(!value.validate(&schema));
-        assert_log_message(
+        assert_logged(
             format!(
                 "Invalid value: {:?} for schema: {:?}. Reason: {}",
                 value, schema, "No symbol at position '1000'"
@@ -1193,7 +1150,7 @@ mod tests {
 
         let value = Value::String("lorem".to_string());
         assert!(!value.validate(&schema));
-        assert_log_message(
+        assert_logged(
             format!(
                 "Invalid value: {:?} for schema: {:?}. Reason: {}",
                 value, schema, "'lorem' is not a member of the possible symbols"
@@ -1215,7 +1172,7 @@ mod tests {
 
         let value = Value::Enum(0, "spades".to_string());
         assert!(!value.validate(&other_schema));
-        assert_log_message(
+        assert_logged(
             format!(
                 "Invalid value: {:?} for schema: {:?}. Reason: {}",
                 value, other_schema, "Symbol 'spades' is not at position '0'"
@@ -1226,8 +1183,6 @@ mod tests {
 
     #[test]
     fn validate_record() {
-        init();
-
         // {
         //    "type": "record",
         //    "fields": [
@@ -1280,14 +1235,14 @@ mod tests {
             ("b".to_string(), Value::String("foo".to_string())),
         ]);
         assert!(!value.validate(&schema));
-        assert_log_message("Invalid value: Record([(\"a\", Boolean(false)), (\"b\", String(\"foo\"))]) for schema: Record { name: Name { name: \"some_record\", namespace: None }, aliases: None, doc: None, fields: [RecordField { name: \"a\", doc: None, default: None, schema: Long, order: Ascending, position: 0 }, RecordField { name: \"b\", doc: None, default: None, schema: String, order: Ascending, position: 1 }], lookup: {\"a\": 0, \"b\": 1} }. Reason: Unsupported value-schema combination");
+        assert_logged("Invalid value: Record([(\"a\", Boolean(false)), (\"b\", String(\"foo\"))]) for schema: Record { name: Name { name: \"some_record\", namespace: None }, aliases: None, doc: None, fields: [RecordField { name: \"a\", doc: None, default: None, schema: Long, order: Ascending, position: 0 }, RecordField { name: \"b\", doc: None, default: None, schema: String, order: Ascending, position: 1 }], lookup: {\"a\": 0, \"b\": 1} }. Reason: Unsupported value-schema combination");
 
         let value = Value::Record(vec![
             ("a".to_string(), Value::Long(42i64)),
             ("c".to_string(), Value::String("foo".to_string())),
         ]);
         assert!(!value.validate(&schema));
-        assert_log_message(
+        assert_logged(
             "Invalid value: Record([(\"a\", Long(42)), (\"c\", String(\"foo\"))]) for schema: Record { name: Name { name: \"some_record\", namespace: None }, aliases: None, doc: None, fields: [RecordField { name: \"a\", doc: None, default: None, schema: Long, order: Ascending, position: 0 }, RecordField { name: \"b\", doc: None, default: None, schema: String, order: Ascending, position: 1 }], lookup: {\"a\": 0, \"b\": 1} }. Reason: There is no schema field for field 'c'"
         );
 
@@ -1297,7 +1252,7 @@ mod tests {
             ("c".to_string(), Value::Null),
         ]);
         assert!(!value.validate(&schema));
-        assert_log_message(
+        assert_logged(
             r#"Invalid value: Record([("a", Long(42)), ("b", String("foo")), ("c", Null)]) for schema: Record { name: Name { name: "some_record", namespace: None }, aliases: None, doc: None, fields: [RecordField { name: "a", doc: None, default: None, schema: Long, order: Ascending, position: 0 }, RecordField { name: "b", doc: None, default: None, schema: String, order: Ascending, position: 1 }], lookup: {"a": 0, "b": 1} }. Reason: The value's records length (3) is different than the schema's (2)"#,
         );
 
@@ -1317,7 +1272,7 @@ mod tests {
                 .collect()
         )
         .validate(&schema));
-        assert_log_message(
+        assert_logged(
             r#"Invalid value: Map({"c": Long(123)}) for schema: Record { name: Name { name: "some_record", namespace: None }, aliases: None, doc: None, fields: [RecordField { name: "a", doc: None, default: None, schema: Long, order: Ascending, position: 0 }, RecordField { name: "b", doc: None, default: None, schema: String, order: Ascending, position: 1 }], lookup: {"a": 0, "b": 1} }. Reason: Field with name '"a"' is not a member of the map items
 Field with name '"b"' is not a member of the map items"#,
         );

diff --git a/lang/rust/avro/tests/schema.rs b/lang/rust/avro/tests/schema.rs
index c311eb3354ca1cb7713d36bf6a46b2628788964e..8d992e0e207db6bcd361fc877c33e8ed61d2aa26 100644 (file)
--- a/lang/rust/avro/tests/schema.rs
+++ b/lang/rust/avro/tests/schema.rs
@@ -22,14 +22,7 @@ use apache_avro::{
     Codec, Error, Reader, Schema, Writer,
 };
 use lazy_static::lazy_static;
-use log::debug;
-
-fn init() {
-    let _ = env_logger::builder()
-        .filter_level(log::LevelFilter::Trace)
-        .is_test(true)
-        .try_init();
-}
+use apache_avro_test_helper::init;
 
 const PRIMITIVE_EXAMPLES: &[(&str, bool)] = &[
     (r#""null""#, true),
@@ -641,7 +634,6 @@ fn test_correct_recursive_extraction() {
 #[test]
 fn test_parse() {
     init();
-
     for (raw_schema, valid) in EXAMPLES.iter() {
         let schema = Schema::parse_str(raw_schema);
         if *valid {
@@ -1176,7 +1168,6 @@ fn test_fullname_name_namespace_and_default_namespace_specified() {
 #[test]
 fn test_doc_attributes() {
     init();
-
     fn assert_doc(schema: &Schema) {
         match schema {
             Schema::Enum { doc, .. } => assert!(doc.is_some()),
@@ -1235,7 +1226,6 @@ fn test_other_attributes() {
 #[test]
 fn test_root_error_is_not_swallowed_on_parse_error() -> Result<(), String> {
     init();
-
     let raw_schema = r#"/not/a/real/file"#;
     let error = Schema::parse_str(raw_schema).unwrap_err();
 
@@ -1257,6 +1247,7 @@ fn test_root_error_is_not_swallowed_on_parse_error() -> Result<(), String> {
 // AVRO-3302
 #[test]
 fn test_record_schema_with_cyclic_references() {
+    init();
     let schema = Schema::parse_str(
         r#"
             {
@@ -1314,7 +1305,7 @@ fn test_record_schema_with_cyclic_references() {
 
     match Reader::new(&mut bytes.as_slice()) {
         Ok(mut reader) => match reader.next() {
-            Some(value) => debug!("{:?}", value.unwrap()),
+            Some(value) => log::debug!("{:?}", value.unwrap()),
             None => panic!("No value was read!"),
         },
         Err(err) => panic!("An error occurred while reading datum: {:?}", err),
@@ -1325,6 +1316,7 @@ fn test_record_schema_with_cyclic_references() {
 // TODO: (#93) add support for logical type and attributes and uncomment (may need some tweaks to compile)
 #[test]
 fn test_decimal_valid_type_attributes() {
+    init();
     let fixed_decimal = Schema::parse_str(DECIMAL_LOGICAL_TYPE_ATTRIBUTES[0]).unwrap();
     assert_eq!(4, fixed_decimal.get_attribute("precision"));
     assert_eq!(2, fixed_decimal.get_attribute("scale"));

diff --git a/lang/rust/avro_test_helper/Cargo.toml b/lang/rust/avro_test_helper/Cargo.toml
new file mode 100644 (file)
index 0000000..6cddb61
--- /dev/null
+++ b/lang/rust/avro_test_helper/Cargo.toml
@@ -0,0 +1,13 @@
+[package]
+name = "apache-avro-test-helper"
+version = "0.1.0"
+edition = "2018"
+description = "Avro test helper. This crate is not supposed to be published!"
+
+[dependencies]
+ctor = "0.1.22"
+color-backtrace = { version = "0.5" }
+env_logger = "0.9.0"
+lazy_static = { default-features = false, version="1.4.0" }
+log = { default-features = false, version="0.4.16" }
+ref_thread_local = "0.1.1"

diff --git a/lang/rust/avro_test_helper/README.md b/lang/rust/avro_test_helper/README.md
new file mode 100644 (file)
index 0000000..1106475
--- /dev/null
+++ b/lang/rust/avro_test_helper/README.md
@@ -0,0 +1,48 @@
+<!---
+  Licensed to the Apache Software Foundation (ASF) under one
+  or more contributor license agreements.  See the NOTICE file
+  distributed with this work for additional information
+  regarding copyright ownership.  The ASF licenses this file
+  to you under the Apache License, Version 2.0 (the
+  "License"); you may not use this file except in compliance
+  with the License.  You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+  Unless required by applicable law or agreed to in writing,
+  software distributed under the License is distributed on an
+  "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+  KIND, either express or implied.  See the License for the
+  specific language governing permissions and limitations
+  under the License.
+-->
+
+
+# Avro Test Helper
+
+A module that provides several test related goodies to the other Avro crates:
+
+### Custom Logger
+
+The logger both collects the logged messages and delegates to env_logger so that they printed on the stderr
+
+### Colorized Backtraces
+
+Uses `color-backtrace` to make the backtraces easier to read.
+
+# Setup
+
+### Unit tests
+
+The module is automatically setup for all unit tests when this crate is listed as a `[dev-dependency]` in Cargo.toml.
+
+### Integration tests
+
+Since integration tests are actually crates without Cargo.toml, the test author needs to call `test_logger::init()` in the beginning of a test.
+
+# Usage
+
+To assert that a given message was logged, use the `assert_logged` function.
+```rust
+assert_logged("An expected message");
+```

diff --git a/lang/rust/avro_test_helper/src/lib.rs b/lang/rust/avro_test_helper/src/lib.rs
new file mode 100644 (file)
index 0000000..4fc6bb3
--- /dev/null
+++ b/lang/rust/avro_test_helper/src/lib.rs
@@ -0,0 +1,31 @@
+use ctor::{ctor, dtor};
+
+use ref_thread_local::ref_thread_local;
+
+ref_thread_local! {
+    // The unit tests run in parallel
+    // We need to keep the log messages in a thread-local variable
+    // and clear them after assertion
+    pub static managed LOG_MESSAGES: Vec<String> = Vec::new();
+}
+
+pub mod logger;
+
+#[ctor]
+fn setup() {
+    // better stacktraces in tests
+    color_backtrace::install();
+
+    // enable logging in tests
+    logger::setup();
+}
+
+#[dtor]
+fn teardown() {
+    logger::clear_log_messages();
+}
+
+/// Does nothing. Just loads the crate.
+/// Should be used in the integration tests, because they do not use [dev-dependencies]
+/// and do not auto-load this crate.
+pub const fn init() {}

diff --git a/lang/rust/avro_test_helper/src/logger.rs b/lang/rust/avro_test_helper/src/logger.rs
new file mode 100644 (file)
index 0000000..f4dbc27
--- /dev/null
+++ b/lang/rust/avro_test_helper/src/logger.rs
@@ -0,0 +1,51 @@
+use crate::LOG_MESSAGES;
+use lazy_static::lazy_static;
+use log::{LevelFilter, Log, Metadata};
+use ref_thread_local::RefThreadLocal;
+
+struct TestLogger {
+    delegate: env_logger::Logger,
+}
+
+impl Log for TestLogger {
+    fn enabled(&self, _metadata: &Metadata) -> bool {
+        true
+    }
+
+    fn log(&self, record: &log::Record) {
+        if self.enabled(record.metadata()) {
+            LOG_MESSAGES.borrow_mut().push(format!("{}", record.args()));
+
+            self.delegate.log(record);
+        }
+    }
+
+    fn flush(&self) {}
+}
+
+lazy_static! {
+    // Lazy static because the Logger has to be 'static
+    static ref TEST_LOGGER: TestLogger = TestLogger {
+        delegate: env_logger::Builder::from_default_env()
+            .filter_level(LevelFilter::Off)
+            .parse_default_env()
+            .build(),
+    };
+}
+
+pub fn clear_log_messages() {
+    LOG_MESSAGES.borrow_mut().clear();
+}
+
+pub fn assert_logged(expected_message: &str) {
+    assert_eq!(LOG_MESSAGES.borrow_mut().pop().unwrap(), expected_message);
+}
+
+pub(crate) fn setup() {
+    log::set_logger(&*TEST_LOGGER)
+        .map(|_| log::set_max_level(LevelFilter::Trace))
+        .map_err(|err| {
+            eprintln!("========= Failed to set the custom logger: {}", err);
+        })
+        .unwrap();
+}