Skip to content

feat utest: introduce LoggingFixture#1143

Open
Turim wants to merge 2 commits intouserver-framework:developfrom
Turim:feature/utest-logging-fixture
Open

feat utest: introduce LoggingFixture#1143
Turim wants to merge 2 commits intouserver-framework:developfrom
Turim:feature/utest-logging-fixture

Conversation

@Turim
Copy link
Contributor

@Turim Turim commented Mar 15, 2026

Motivation:

  • it is hard to unittest C++ code that are parts of the app without decent logger

Note: by creating a PR or an issue you automatically agree to the CLA. See CONTRIBUTING.md. Feel free to remove this note, the agreement holds.

}
};

} // namespace detail
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Btw I'm not sure, but may be if we provide LoggingFixtureEx along with, we'd better get LoggingFixtureEnvironment outta detail namespace?


void Log(logging::Level level, logging::impl::formatters::LoggerItemRef item) override
{
UASSERT(dynamic_cast<logging::impl::TextLogItem*>(&item));
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not sure here also: may be it's enough to check via static_cast on the next line.


namespace detail {

class CoutLogger final : public logging::impl::TextLogger {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What do you think, is it decent to propose logger change: get TextLogger out of the impl namespace?
The assumed downside: might be there would be a client which would use the class on a regular basis..

{
LOG_INFO() << "Test message";
}

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shall we provide an example on DerivedEnvironment or the usage is obvious?

@Turim
Copy link
Contributor Author

Turim commented Mar 15, 2026

I have no clue about the build issue(

e.g. gRPC? re2? it seems unrelated to me.

...
Overrides
    icu/73.2: ['icu/76.1']
    protobuf/[>=5.27.0 <7]: ['protobuf/[^5.27]']
    abseil/[*]: ['abseil/20240116.2#f223c3320ef9e6feee1d904ae925197d']
    abseil/[>=20230802.1 <=20250127.0]: ['abseil/20240116.2']
ERROR: Version conflict: Conflict between re2/[>=20251105] and re2/20230301 in the graph.
Conflict originates from grpc/1.78.1

Run 'conan graph info ... --format=html > graph.html' and open 'graph.html' to inspect the conflict graphically.
Error: Process completed with exit code 1.

@apolukhin
Copy link
Member

Looks like the command line option --log-level=debug does the same thing https://userver.tech/d4/d70/md_en_2userver_2testing.html#autotoc_md958

@Turim Am I missing something?

@Turim
Copy link
Contributor Author

Turim commented Mar 17, 2026

Hi, Antony,

Looks like the command line option --log-level=debug does the same thing https://userver.tech/d4/d70/md_en_2userver_2testing.html#autotoc_md958

Might be I'm shortened the Motivation, so I'll try to clarify here then:

  1. When one uses --log-level=debug, it configures (let's call it that way) log-collector to not ignore the log messages with that level (or above/below);
  2. Expectation: collected log messages would be put to some real logger (=they would get printed on STDOUT, for instance, by some code). But really without (let's call it that way) log-sink nothing happens. The mentioned link https://userver.tech/d4/d70/md_en_2userver_2testing.html#autotoc_md958 shows us that logger tests has some logger sink within. But the other part of the userver-core-unittest doesn't .

So, on the one hand, I'm not sure (you'd better clarify, please) if the mentioned logger-tests-sink are appropriate to be shared across the userver-core-unittest and abroad in the userver testing scenario. (from the 1st glance they are not)

On the other hand, when some dev wants to see (=print, log) userver's (and/or written via userver) structures in it's own tests, he doesn't have the option other than to write a logger sink (=e.g. reinvent the fixture somehow) (Hopefully it's possible today at all - please, if possible, don't drop this option, I've mentioned about the impl:: namespace above)
Upd. For instance, some dev might build tests atop of userver-sqlite*, userver-postgres* (and so on) and expects to see the log messages.

CoutLogger() : TextLogger(logging::Format::kTskv)
{
#if 0
// Actually in the case we see some manipulation with the level and in the end it doesn't work expected way
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seems to me that 1. on --trace_level=debug

[ RUN      ] LoggingFixture.DebugMessage
tskv    timestamp=2026-03-17T23:51:21.289074    level=INFO      module=Start ( core/src/engine/coro/stack_usage_monitor.cpp:319 )       task_id=0       thread_id=0x0000748B659FBC00  text=Successfully initialized StackUsageMonitor, kernel supports following userfaultfd features: 131071
tskv    timestamp=2026-03-17T23:51:21.289432    level=DEBUG     module=AcquireEvDefaultLoop ( core/src/engine/ev/event_loop.cpp:36 )    task_id=0       thread_id=0x0000748B659FBC00  text=Acquire ev_default_loop for thread_name=userver-utest-u
tskv    timestamp=2026-03-17T23:51:21.289530    level=INFO      module=StateBase ( core/src/engine/deadlock_detector.cpp:129 )  task_id=0       thread_id=0x0000748B659FBC00  text=Deadlock detector is disabled, stacktraces collection is disabled
tskv    timestamp=2026-03-17T23:51:21.289615    level=INFO      module=TaskProcessor ( core/src/engine/task/task_processor.cpp:143 )    task_id=0       thread_id=0x0000748B659FBC00  text=creating task_processor  worker_threads=1 thread_name=coro-runner
128142014411776 debug   tskv    timestamp=2026-03-17T23:51:21.300360    level=DEBUG     module=TestBody ( core/utest/src/utest/logging_fixture_test.cpp:13 ) text=Test message

we see a lot of implementation details (e.g. TaskProcessor/thread/loop)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

  1. on --trace_level=info it works unexpected way. So I'd better leave unconfigured kDebug for the case.

What do you think?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants