openal-soft icon indicating copy to clipboard operation
openal-soft copied to clipboard

fmt crash

Open hsdk123 opened this issue 11 months ago • 14 comments

Hi, I'm not sure why, but I seem to (sometimes) get a crash here: https://github.com/kcat/openal-soft/blob/master/alc/alc.cpp#L3051

The crash occurs at:

FMT_FUNC void assert_fail(const char* file, int line, const char* message) {
  // Use unchecked std::fprintf to avoid triggering another assertion when
  // writing to stderr fails.
  fprintf(stderr, "%s:%d: assertion failed: %s", file, line, message);
  abort();
}

with message being negative value

Logs:

[ALSOFT] (II) Initializing library v1.24.2-b621b5f master
[ALSOFT] (II) Supported backends: wasapi, dsound, winmm, null, wave
[ALSOFT] (II) Loading config C:\Users\daego\AppData\Roaming\alsoft.ini...
[ALSOFT] (II) Got binary: C:\Users\daego\Desktop\Projects\Light.vn-core\core\bin-Windows-Debug8-Clang-cored, LightTests.exe
[ALSOFT] (II) Loading config C:\Users\daego\Desktop\Projects\Light.vn-core\core\bin-Windows-Debug8-Clang-cored\alsoft.ini...
[ALSOFT] (II) Vendor ID: ""
[ALSOFT] (II) Name: "Intel(R) Core(TM) i7-8700 CPU @ 3.20GHz"
[ALSOFT] (II) Extensions: +SSE +SSE2 +SSE3 +SSE4.1
[ALSOFT] (II) Starting watcher thread
'LightTests.exe' (Win32): Loaded 'C:\Windows\System32\clbcatq.dll'. Symbol loading disabled by Include/Exclude setting.
'LightTests.exe' (Win32): Loaded 'C:\Windows\System32\MMDevAPI.dll'. Symbol loading disabled by Include/Exclude setting.
[ALSOFT] (II) Initialized backend "wasapi"
[ALSOFT] (II) Added "wasapi" for playback
[ALSOFT] (II) Added "wasapi" for capture
[ALSOFT] (II) Opening playback device "OpenAL Soft"
Unhandled exception at 0x00007FFA6495AE6A (ucrtbased.dll) in LightTests.exe: Fatal program exit requested.

hsdk123 avatar Jan 25 '25 20:01 hsdk123

I notice in the stack trace it crashes at:

template <typename Visitor>
FMT_CONSTEXPR FMT_INLINE auto visit(Visitor&& vis) const -> decltype(vis(0)) {
  using detail::map;
  switch (type_) {
  case detail::type::none_type:        break;
  case detail::type::int_type:         return vis(value_.int_value);
  case detail::type::uint_type:        return vis(value_.uint_value);
  case detail::type::long_long_type:   return vis(value_.long_long_value);
  case detail::type::ulong_long_type:  return vis(value_.ulong_long_value);
  case detail::type::int128_type:      return vis(map(value_.int128_value));
  case detail::type::uint128_type:     return vis(map(value_.uint128_value));
  case detail::type::bool_type:        return vis(value_.bool_value);
  case detail::type::char_type:        return vis(value_.char_value);
  case detail::type::float_type:       return vis(value_.float_value);
  case detail::type::double_type:      return vis(value_.double_value);
  case detail::type::long_double_type: return vis(value_.long_double_value);
  case detail::type::cstring_type:     return vis(value_.string.data);
  case detail::type::string_type:      return vis(value_.string.str());
  case detail::type::pointer_type:     return vis(value_.pointer);
  case detail::type::custom_type:      return vis(handle(value_.custom));
  }
  return vis(monostate());
}

case detail::type::pointer_type: return vis(value_.pointer); making it likely the pointer is related?

hsdk123 avatar Jan 25 '25 20:01 hsdk123

Are you able to provide a stack trace? From the looks of it, something in fmt is calling its to_unsigned function with a negative value, but it's not clear where (or why) that would be happening. Especially with a pointer type that's not an integer.

kcat avatar Jan 25 '25 20:01 kcat

Are you able to provide a stack trace? From the looks of it, something in fmt is calling its to_unsigned function with a negative value, but it's not clear where (or why) that would be happening. Especially with a pointer type that's not an integer.

Here it is:

 	ucrtbased.dll!00007ffa45c7ae6a()	Unknown
>	LightTests.exe!fmt::v11::detail::assert_fail(const char * file, int line, const char * message) Line 40	C++
 	LightTests.exe!fmt::v11::detail::to_unsigned<int>(int value) Line 438	C++
 	LightTests.exe!fmt::v11::detail::write_padded<char,2,fmt::v11::basic_appender<char>,`lambda at C:\Users\daego\Desktop\Projects\Light.vn-core\_deps\openal-soft\3be63b3f39a174450de1f24ffd50073c72bb031a\fmt-11.1.1\include\fmt\format.h:1670:16' &>(fmt::v11::basic_appender<char> out, const fmt::v11::format_specs & specs, unsigned __int64 size, unsigned __int64 width, fmt::v11::detail::write_ptr<char,fmt::v11::basic_appender<char>,unsigned long long>::void <lambda>(unsigned __int64) & f) Line 1633	C++
 	LightTests.exe!fmt::v11::detail::write_padded<char,2,fmt::v11::basic_appender<char>,`lambda at C:\Users\daego\Desktop\Projects\Light.vn-core\_deps\openal-soft\3be63b3f39a174450de1f24ffd50073c72bb031a\fmt-11.1.1\include\fmt\format.h:1670:16' &>(fmt::v11::basic_appender<char> out, const fmt::v11::format_specs & specs, unsigned __int64 size, fmt::v11::detail::write_ptr<char,fmt::v11::basic_appender<char>,unsigned long long>::void <lambda>(unsigned __int64) & f) Line 1652	C++
 	LightTests.exe!fmt::v11::detail::write_ptr<char,fmt::v11::basic_appender<char>,unsigned long long>(fmt::v11::basic_appender<char> out, unsigned __int64 value, const fmt::v11::format_specs * specs) Line 1675	C++
 	LightTests.exe!fmt::v11::detail::write<char,fmt::v11::basic_appender<char>,void,0>(fmt::v11::basic_appender<char> out, const void * value, const fmt::v11::format_specs & specs, fmt::v11::detail::locale_ref) Line 3432	C++
 	LightTests.exe!fmt::v11::detail::default_arg_formatter<char>::operator()<const void *,0>(const void * value) Line 3462	C++
 	LightTests.exe!fmt::v11::basic_format_arg<fmt::v11::context>::visit<fmt::v11::detail::default_arg_formatter<char>>(fmt::v11::detail::default_arg_formatter<char> && vis) Line 2499	C++
 	LightTests.exe!fmt::v11::detail::format_handler<char>::on_replacement_field(int id, const char *) Line 3596	C++
 	LightTests.exe!fmt::v11::detail::parse_replacement_field<char,fmt::v11::detail::format_handler<char> &>(const char * begin, const char * end, fmt::v11::detail::format_handler<char> & handler) Line 1571	C++
 	LightTests.exe!fmt::v11::detail::parse_format_string<char,fmt::v11::detail::format_handler<char>>(fmt::v11::basic_string_view<char> fmt, fmt::v11::detail::format_handler<char> && handler) Line 1613	C++
 	LightTests.exe!fmt::v11::detail::vformat_to(fmt::v11::detail::buffer<char> & buf, fmt::v11::basic_string_view<char> fmt, fmt::v11::basic_format_args<fmt::v11::context> args, fmt::v11::detail::locale_ref loc) Line 1457	C++
 	LightTests.exe!fmt::v11::vformat(fmt::v11::basic_string_view<char> fmt, fmt::v11::basic_format_args<fmt::v11::context> args) Line 1444	C++
 	LightTests.exe!al_print_impl(LogLevel level, const fmt::v11::basic_string_view<char> fmt, fmt::v11::basic_format_args<fmt::v11::context> args) Line 85	C++
 	LightTests.exe!al_print<void *,std::string &>(LogLevel level, fmt::v11::fstring<void *,std::string &> fmt, void * && args, std::string & args) Line 31	C++
 	LightTests.exe!alcOpenDevice(const char * deviceName) Line 3052	C++
 	LightTests.exe!Magnum::Audio::Context::tryCreate(const Magnum::Audio::Context::Configuration & configuration) Line 213	C++
 	LightTests.exe!Magnum::Audio::Context::create(const Magnum::Audio::Context::Configuration & configuration) Line 205	C++
 	LightTests.exe!Magnum::Audio::Context::Context(const Magnum::Audio::Context::Configuration & configuration, int argc, const char * const * argv) Line 209	C++
 	LightTests.exe!Magnum::Audio::Context::Context(const Magnum::Audio::Context::Configuration & configuration) Line 212	C++
 	[External Code]	
 	LightTests.exe!lvn::CAudioMgr::CAudioMgr() Line 22	C++
 	[External Code]	
 	LightTests.exe!CoreUtility::Singleton<lvn::CAudioMgr>::CreateInstance<>() Line 30	C++
 	LightTests.exe!main(int argc, char * * argv) Line 100	C++
 	LightTests.exe!wmain(int argc, wchar_t * * wargv) Line 141	C++
 	[External Code]	

hsdk123 avatar Jan 25 '25 22:01 hsdk123

Just a thought, but looking at to_unsigned<int>, maybe this is an overflow issue?

hsdk123 avatar Jan 25 '25 22:01 hsdk123

It doesn't look like it, but I'm not seeing where the problem is, either. And some things don't make sense.

For one, it lists the point in to_unsigned<int>(int value) on Line 438 in fmt/base.h, however line 438 is where it does the static_cast, while the FMT_ASSERT that's failing is on line 437. But that aside, going backwards from there we see the call to to_unsigned is on line 1633 in fmt/format.h:

unsigned spec_width = to_unsigned(specs.width);

Tracing backwards more, we find specs is a default-initialized parameter here:

template <typename Char, typename OutputIt, typename T,
          FMT_ENABLE_IF(std::is_same<T, void>::value)>
auto write(OutputIt out, const T* value, const format_specs& specs = {},
           locale_ref = {}) -> OutputIt {
  return write_ptr<Char>(out, bit_cast<uintptr_t>(value), &specs);
}

Which makes sense since the formatter is specified as {}, making it all defaults. From here, format_specs is pretty simple:

// Format specifiers for built-in and string types.
struct format_specs : basic_specs {
  int width;
  int precision;

  constexpr format_specs() : width(0), precision(-1) {}
};

So specs.width should be 0, meaning the assert:

FMT_ASSERT(std::is_unsigned<Int>::value || value >= 0, "negative value");

should pass since value >= 0. Some more logging would be needed to figure out how either specs.width is being changed, or why to_unsigned gets a different value.

Out of curiosity, are you using static linking for OpenAL Soft? And if so, are you also using (or static linking something else that also uses) a copy of fmt?

kcat avatar Jan 25 '25 23:01 kcat

Just for reference,

TRACE("Created device {}, \"{}\"", voidp{device.get()}, device->mDeviceName);

this line seems to take an extremely long time to process even when it doesn't crash, unsure why.

Out of curiosity, are you using static linking for OpenAL Soft? And if so, are you also using (or static linking something else that also uses) a copy of fmt?

I'm both static linking OpenAL Soft, and static linking my own copy of fmt.

hsdk123 avatar Jan 25 '25 23:01 hsdk123

The reason for the long time seems to be here:

template <typename Char, align default_align = align::left, typename OutputIt,
          typename F>
FMT_CONSTEXPR auto write_padded(OutputIt out, const format_specs& specs,
                                size_t size, size_t width, F&& f) -> OutputIt {
  static_assert(default_align == align::left || default_align == align::right,
                "");
  unsigned spec_width = to_unsigned(specs.width);
  size_t padding = spec_width > width ? spec_width - width : 0;
  // Shifts are encoded as string literals because static constexpr is not
  // supported in constexpr functions.
  auto* shifts =
      default_align == align::left ? "\x1f\x1f\x00\x01" : "\x00\x1f\x00\x01";
  size_t left_padding = padding >> shifts[static_cast<int>(specs.align())];
  size_t right_padding = padding - left_padding;
  auto it = reserve(out, size + padding * specs.fill_size());
  if (left_padding != 0) it = fill<Char>(it, left_padding, specs);
  it = f(it);
  if (right_padding != 0) it = fill<Char>(it, right_padding, specs);
  return base_iterator(out, it);
}

Specifically, if (left_padding != 0) it = fill<Char>(it, left_padding, specs); for whatosever reason, left_paddding is 2447048463, which is a huge number.

hsdk123 avatar Jan 25 '25 23:01 hsdk123

For reference, value_.pointer on base.h 2499 is 0x000002d71b9cc0f0

hsdk123 avatar Jan 25 '25 23:01 hsdk123

So specs.width should be 0

According to the debugger, the value seems to be 1847918820

hsdk123 avatar Jan 25 '25 23:01 hsdk123

Just as a side note, it would be great if as a user I could modify https://github.com/kcat/openal-soft/blob/master/core/logging.h#L16

It might not cover all cases, but being able to set it ex. before I start openal would help work around these cases.

hsdk123 avatar Jan 26 '25 00:01 hsdk123

That shouldn't happen either, since spec_width should be 0, so padding (and left_padding) should end up as 0 too.

I think the issue might be because:

I'm both static linking OpenAL Soft, and static linking my own copy of fmt.

This would result in two copies of fmt being linked together, which if they're not the same version or compiled the same, could result in ODR (One Definition Rule) violations. In particular, if the compiler doesn't inline certain functions it will output an instance of the function body in the object file and generate a call to it, while at link time, the compiler will see multiple versions of the function and pick one to place in the resulting executable. If the version of the function picked doesn't behave as a given caller expects, like it assumes the wrong padding for structs or placement of struct members, or expects parameters passed in different ways, it could end up reading wrong/junk values.

If that's the problem, it might not be too hard to fix. In fmt/base.h around line 255, there's the line:

inline namespace v11 {

You can change that v11 to something else. For OpenAL Soft's copy, it can be changed to something like v11alsoft, and your copy can be changed to v11lt or anything else that won't clash. That will change the symbol names of the generated/called functions, so OpenAL Soft and your app will effectively have separate fmt functions and not call the wrong/unexpected version.

Just as a side note, it would be great if as a user I could modify https://github.com/kcat/openal-soft/blob/master/core/logging.h#L16

That's what the ALSOFT_LOGLEVEL environment variable controls. 0 sets it to Disable, 1 to Error, etc.

kcat avatar Jan 26 '25 00:01 kcat

Thank you, I only needed to update the namespace in openalsoft's version, and now things are fine!

https://github.com/hsdk123/openal-soft/blob/master/fmt-11.1.1/include/fmt/base.h#L255

If an official update can be made, I'd be happy to get rid of my fork.

hsdk123 avatar Jan 26 '25 01:01 hsdk123

That's what the ALSOFT_LOGLEVEL environment variable controls. 0 sets it to Disable, 1 to Error, etc.

As this is a user application, and my users don't know much about environment variables, this sadly isn't a viable option...

hsdk123 avatar Jan 26 '25 01:01 hsdk123

1.24.3 is released with the namespace fix.

kcat avatar Mar 30 '25 04:03 kcat