Тупик в методе std :: filebuf open между двумя потоками - PullRequest
0 голосов
/ 24 июня 2019

У меня есть приложение на c ++, в котором есть несколько потоков демонов, которые работают бесконечно, что делает некоторые записи и ротацию файлов.

Это приложение работало нормально, когда оно было скомпилировано с VS2010. Но когда я обновил и скомпилировал его с VS 2017, между этими двумя потоками возникает странная тупиковая ситуация, которая приводит к зависанию приложения.

Я проанализировал дамп exe с помощью windbg .. Вот стек двух потоков.

0:000> ~13 k
# Child-SP          RetAddr           Call Site
00 000000ab`3aabed48 00007fff`5424de39 ntdll!NtWaitForSingleObject+0xa
01 000000ab`3aabed50 00007fff`5424b7e4 ntdll!RtlpWaitOnCriticalSection+0xe1
02 000000ab`3aabee20 00007fff`4c1161e0 ntdll!RtlpEnterCriticalSectionContended+0xa4
03 000000ab`3aabee60 00007fff`4c1160d5 ucrtbase!__acrt_stdio_allocate_stream+0x130
04 000000ab`3aabeea0 00007fff`4c112578 ucrtbase!__acrt_stdio_allocate_stream+0x25
05 000000ab`3aabeed0 00007fff`4c331660 ucrtbase!fsopen+0x58
06 (Inline Function) --------`-------- msvcp140!std::_Xfsopen+0x14 [d:\agent\_work\2\s\src\vctools\crt\crtw32\stdcpp\fiopen.cpp @ 17] 
07 000000ab`3aabef20 00007fff`44a6b3a3 msvcp140!std::_Xfiopen<char>+0xe0 [d:\agent\_work\2\s\src\vctools\crt\crtw32\stdcpp\fiopen.cpp @ 90] 
08 000000ab`3aabef50 00007fff`44a6c89c jsonout_plugin!genint::lib::rotatable_ofstream::do_open+0x83
09 000000ab`3aabefd0 00007fff`44a6d9cb jsonout_plugin!genint::lib::rotatable_ofstream::rotate+0xb7c
0a 000000ab`3aabf2b0 00007fff`44a6d494 jsonout_plugin!genint::lib::rotatable_ofstream::update+0x1db
0b 000000ab`3aabf320 00007fff`4c331ed3 jsonout_plugin!genint::lib::rotatable_ofstream::observable_filebuf::sync+0x64
0c (Inline Function) --------`-------- msvcp140!std::basic_streambuf<char,std::char_traits<char> >::pubsync+0xd [d:\agent\_work\2\s\src\vctools\crt\crtw32\stdhpp\streambuf @ 143] 
0d 000000ab`3aabf350 00007fff`44a5661f msvcp140!std::basic_ostream<char,std::char_traits<char> >::flush+0x53 [d:\agent\_work\2\s\src\vctools\crt\crtw32\stdhpp\ostream @ 591] 
0e 000000ab`3aabf3d0 00007fff`44a51c11 jsonout_plugin!std::endl<char,std::char_traits<char> >+0x43
0f 000000ab`3aabf400 00007ff7`98e0dbc5 jsonout_plugin!genint::jsonout_plugin::json_sink_node::execute+0x14d
10 000000ab`3aabf620 00007ff7`98ddf10c genintd!genint::pipeline::node_lifecycle_impl<1>::execute+0x2d
11 000000ab`3aabf650 00007ff7`98de39eb genintd!genint::pipeline::node::thread_run+0x100
12 000000ab`3aabf750 00007ff7`98de4a36 genintd!boost::_bi::bind_t<void,std::mem_fun_t<void,genint::pipeline::node>,boost::_bi::list1<boost::_bi::value<genint::pipeline::node * __ptr64> > >::operator()+0x23
13 000000ab`3aabf790 00007ff7`98e2ebc3 genintd!boost::detail::thread_data<boost::_bi::bind_t<void,std::mem_fun_t<void,genint::pipeline::node>,boost::_bi::list1<boost::_bi::value<genint::pipeline::node * __ptr64> > > >::run+0x1a
14 000000ab`3aabf7c0 00007fff`4c12cd70 genintd!boost::system::system_category+0x53
15 000000ab`3aabf800 00007fff`520e13d2 ucrtbase!o__realloc_base+0x60
16 000000ab`3aabf830 00007fff`542254f4 kernel32!BaseThreadInitThunk+0x22
17 000000ab`3aabf860 00000000`00000000 ntdll!RtlUserThreadStart+0x34
0:000> ~9 k
# Child-SP          RetAddr           Call Site
00 000000ab`3a4bf1a8 00007fff`5424de39 ntdll!NtWaitForSingleObject+0xa
01 000000ab`3a4bf1b0 00007fff`5424b7e4 ntdll!RtlpWaitOnCriticalSection+0xe1
02 000000ab`3a4bf280 00007fff`4c1160ca ntdll!RtlpEnterCriticalSectionContended+0xa4
03 000000ab`3a4bf2c0 00007fff`4c112578 ucrtbase!__acrt_stdio_allocate_stream+0x1a
04 000000ab`3a4bf2f0 00007fff`4c331660 ucrtbase!fsopen+0x58
05 (Inline Function) --------`-------- msvcp140!std::_Xfsopen+0x14 [d:\agent\_work\2\s\src\vctools\crt\crtw32\stdcpp\fiopen.cpp @ 17] 
06 000000ab`3a4bf340 00007fff`44d1bbd3 msvcp140!std::_Xfiopen<char>+0xe0 [d:\agent\_work\2\s\src\vctools\crt\crtw32\stdcpp\fiopen.cpp @ 90] 
07 000000ab`3a4bf370 00007fff`44d1cd9c xmlout_plugin!genint::lib::rotatable_ofstream::do_open+0x83
08 000000ab`3a4bf3f0 00007fff`44d1d8eb xmlout_plugin!genint::lib::rotatable_ofstream::rotate+0xb7c
09 000000ab`3a4bf6d0 00007fff`44d1d6f4 xmlout_plugin!genint::lib::rotatable_ofstream::update+0x1db
0a 000000ab`3a4bf740 00007fff`4c331ed3 xmlout_plugin!genint::lib::rotatable_ofstream::observable_filebuf::sync+0x64
0b (Inline Function) --------`-------- msvcp140!std::basic_streambuf<char,std::char_traits<char> >::pubsync+0xd [d:\agent\_work\2\s\src\vctools\crt\crtw32\stdhpp\streambuf @ 143] 
0c 000000ab`3a4bf770 00007fff`44d0b22b msvcp140!std::basic_ostream<char,std::char_traits<char> >::flush+0x53 [d:\agent\_work\2\s\src\vctools\crt\crtw32\stdhpp\ostream @ 591] 
0d 000000ab`3a4bf7f0 00007fff`44d141ee xmlout_plugin!std::endl<char,std::char_traits<char> >+0x43
0e 000000ab`3a4bf820 00007ff7`98e0dbc5 xmlout_plugin!genint::xmlout_plugin::xml_sink_node::execute+0x16a
0f 000000ab`3a4bfa40 00007ff7`98ddf10c genintd!genint::pipeline::node_lifecycle_impl<1>::execute+0x2d
10 000000ab`3a4bfa70 00007ff7`98de39eb genintd!genint::pipeline::node::thread_run+0x100
11 000000ab`3a4bfb70 00007ff7`98de4a36 genintd!boost::_bi::bind_t<void,std::mem_fun_t<void,genint::pipeline::node>,boost::_bi::list1<boost::_bi::value<genint::pipeline::node * __ptr64> > >::operator()+0x23
12 000000ab`3a4bfbb0 00007ff7`98e2ebc3 genintd!boost::detail::thread_data<boost::_bi::bind_t<void,std::mem_fun_t<void,genint::pipeline::node>,boost::_bi::list1<boost::_bi::value<genint::pipeline::node * __ptr64> > > >::run+0x1a
13 000000ab`3a4bfbe0 00007fff`4c12cd70 genintd!boost::system::system_category+0x53
14 000000ab`3a4bfc20 00007fff`520e13d2 ucrtbase!o__realloc_base+0x60
15 000000ab`3a4bfc50 00007fff`542254f4 kernel32!BaseThreadInitThunk+0x22
16 000000ab`3a4bfc80 00000000`00000000 ntdll!RtlUserThreadStart+0x34

Из! Замков. Показывает, что есть тупик.

0:000> !locks

CritSec +398bb080 at 000000ab398bb080
WaiterWoken        No
LockCount          1
RecursionCount     1
OwningThread       8fc
EntryCount         0
ContentionCount    1
*** Locked

CritSec ucrtbase!environ_table+160 at 00007fff4c1f6dc0
WaiterWoken        No
LockCount          1
RecursionCount     1
OwningThread       17a4
EntryCount         0
ContentionCount    1
*** Locked

Это код, который выполняется

void pre_open()
{
HANDLE fh = CreateFileA(m_base_filename.c_str(), 
GENERIC_WRITE, 0, NULL, OPEN_ALWAYS, FILE_ATTRIBUTE_ARCHIVE, NULL);
SYSTEMTIME stime;
GetSystemTime(&stime);
FILETIME ftime;
SystemTimeToFileTime(&stime, &ftime);
ULARGE_INTEGER conv;
conv.HighPart = ftime.dwHighDateTime;
conv.LowPart = ftime.dwLowDateTime;
// "Marty! You're not thinking fourth-dimensionally!"
conv.QuadPart += ModificationTimeOffset * 10000000;
ftime.dwHighDateTime = conv.HighPart;
ftime.dwLowDateTime = conv.LowPart;
if (s_logger.get_log_level() >= genint::lib::LogLevelTrace)
{
char timestring_old[100];
char timestring_new[100];
SYSTEMTIME stime_new;
FileTimeToSystemTime(&ftime, &stime_new);
GetTimeFormatA(LOCALE_SYSTEM_DEFAULT, NULL, &stime_new, NULL, timestring_new, 100);
GetTimeFormatA(LOCALE_SYSTEM_DEFAULT, NULL, &stime, NULL, timestring_old, 100);
s_logger.trace()
  << "Setting modification timestamp for file '" << m_base_filename
  << "' to " << std::string(timestring_new)
  << " (current time: " << std::string(timestring_old) << ")";
}
if (!SetFileTime(fh, NULL, NULL, &ftime))
{
  s_logger.warning() 
  << "Failed to set modification timestamp for file '" << m_base_filename << "'";
}
CloseHandle(fh);
}

void rotatable_ofstream::do_open(const char* filename, bool do_update)
{
  pre_open();
  if (m_filebuffer.open(filename, m_open_mode) == 0)
  {
    std::ios::setstate(std::ios_base::failbit);
    s_logger.error() << "Failed to open file '" << m_base_filename << "' !";
  }
}

Приведенный выше код выполняется исключительно в этих двух потоках, так как это определение является частью библиотеки DLL отдельно.

Трассировка стека в дампе показывает, что последней функцией в моем коде является функция do_open (). и этот код вызывает функцию open в std :: fileuf

Как происходит этот тупик или зависание на системном уровне?

Может ли кто-нибудь рассказать об этом?

...