You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@avro.apache.org by mg...@apache.org on 2022/05/17 18:02:18 UTC
[avro] branch better-logging-in-tests created (now 1dc9244a0)
This is an automated email from the ASF dual-hosted git repository.
mgrigorov pushed a change to branch better-logging-in-tests
in repository https://gitbox.apache.org/repos/asf/avro.git
at 1dc9244a0 Use ctor crate to setup/teardown tests
This branch includes the following new commits:
new 1dc9244a0 Use ctor crate to setup/teardown tests
The 1 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails. The revisions
listed as "add" were already present in the repository and have only
been added to this reference.
[avro] 01/01: Use ctor crate to setup/teardown tests
Posted by mg...@apache.org.
This is an automated email from the ASF dual-hosted git repository.
mgrigorov pushed a commit to branch better-logging-in-tests
in repository https://gitbox.apache.org/repos/asf/avro.git
commit 1dc9244a03218018fa65671053c9a70723210b94
Author: Martin Tzvetanov Grigorov <mg...@apache.org>
AuthorDate: Tue May 17 13:50:54 2022 +0300
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 <mg...@apache.org>
---
lang/rust/Cargo.toml | 1 +
lang/rust/avro/Cargo.toml | 9 ++---
lang/rust/avro/src/types.rs | 67 ++++++--------------------------
lang/rust/avro/tests/schema.rs | 16 ++------
lang/rust/avro_test_helper/Cargo.toml | 13 +++++++
lang/rust/avro_test_helper/README.md | 48 +++++++++++++++++++++++
lang/rust/avro_test_helper/src/lib.rs | 31 +++++++++++++++
lang/rust/avro_test_helper/src/logger.rs | 51 ++++++++++++++++++++++++
8 files changed, 163 insertions(+), 73 deletions(-)
diff --git a/lang/rust/Cargo.toml b/lang/rust/Cargo.toml
index 9f188c065..527bfb3fe 100644
--- 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 268cdfb2d..389c41dba 100644
--- 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 78b000552..93045ee65 100644
--- 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 sche [...]
);
@@ -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 c311eb335..8d992e0e2 100644
--- 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
index 000000000..6cddb61c8
--- /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
index 000000000..11064757f
--- /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
index 000000000..4fc6bb30e
--- /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
index 000000000..f4dbc2750
--- /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();
+}