Deadlock on std::filebuf open method between two threads

Question

I have a c++ application which has multiple daemon threads running infinitely which does some file logging and rotation.

This application was working fine when it was compiled with VS2010. But when i upgraded and compiled it with VS 2017, there is a strange deadlock that is happening between these two threads which causes the application to freeze.

I analyzed the dump of the exe with windbg..Here is the stack of the two threads.

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

Out of !locks. Showing there is deadlock.

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

This is the code that is executed

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 << "' !";
  }
}

The above code exclusively executes in these two threads as this definition is part of the dlls separately.

The stack trace in the dump shows the last function in my code is do_open() function. and this code calls open function on std::fileuf

How does this deadlock or freeze happen at the system level ?

Could someone please give some insights on this ?