aboutsummaryrefslogtreecommitdiffstatshomepage
path: root/_posts/2015-07-03-std-call-once-bug-in-visual-studio-2012-2013.md
blob: 5570979d0ccd146565485eea4a3d0dd63ea564df (plain) (blame)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
---
title: std::call_once bug in Visual Studio 2012/2013
layout: post
excerpt: >
  In this post, I will describe a neat bug I've stumbled upon in C++ Standard
  Library implementation shipped with Microsoft Visual Studio 2012/2013.
custom_css:
  - syntax.css
---
### Abstract

In this post, I will describe a neat bug I've stumbled upon in C++ Standard
Library implementation shipped with Microsoft Visual Studio 2012/2013.

### License

Distributed under the MIT License.
See [LICENSE.txt] for details.

[LICENSE.txt]: {{ site.github.repository_url }}/blob/gh-pages/LICENSE.txt

Introduction
------------

I've recently come across a nasty standard library bug in the implementation
shipped with Microsoft Visual Studio 2012/2013.
[StackOverflow was of no help], so I had to somehow report the bug to the
maintainers.
Oddly enough, Visual Studio's [Connect page] wouldn't let me to report one,
complaining that I supposedly had no right to do so, even though I was logged
in from my work account, associated with my Visual Studio 2013 installation.

Fortunately, I've come across the personal website of this amazing guy,
[Stephan T. Lavavej], who appears to be the chief maintainer of Microsoft's
standard library implementation.
He seems to be your go-to guy when it comes to obvious standard library
misbehaviours.

[StackOverflow was of no help]: https://stackoverflow.com/questions/26477070/concurrent-stdcall-once-calls
[Connect page]: https://connect.microsoft.com/VisualStudio
[Stephan T. Lavavej]: http://nuwen.net/stl.html

C++11 and singletons
--------------------

Anyway, the story begins with me trying to implement the singleton pattern
using C++11 facilities like this:

{% highlight c++ %}
#include <mutex>

template <typename DerivedT>
class Singleton
{
public:
    static DerivedT& get_instance()
    {
        std::call_once(initialized_flag, &initialize_instance);
        return DerivedT::get_instance_unsafe();
    }

protected:
    Singleton() = default;
    ~Singleton() = default;

    static DerivedT& get_instance_unsafe()
    {
        static DerivedT instance;
        return instance;
    }

private:
    static void initialize_instance()
    {
        DerivedT::get_instance_unsafe();
    }

    static std::once_flag initialized_flag;

    Singleton(const Singleton&) = delete;
    Singleton& operator=(const Singleton&) = delete;
};

template <typename DerivedT>
std::once_flag Singleton<DerivedT>::initialized_flag;
{% endhighlight %}

Neat, huh?
Now other classes can inherit from `Singleton`, implementing the singleton
pattern effortlessly:

{% highlight c++ %}
class Logger : public Singleton<Logger>
{
private:
    Logger() = default;
    ~Logger() = default;

    friend class Singleton<Logger>;
};
{% endhighlight %}

Note that the [N2660] standard proposal isn't/wasn't implemented in the
compilers shipped with Visual Studio 2012/2013.
If it was, I wouldn't, of course, need to employ this `std::call_once`
trickery, and the implementation would be much simpler, i.e. something like
this:

{% highlight c++ %}
class Logger
{
public:
    static Logger& get_instance()
    {
        static Logger instance;
        return instance;
    }

private:
    Logger() = default;
    ~Logger() = default;
};
{% endhighlight %}

<div class="alert alert-info">
<p>The point is that the <code>Logger::get_instance</code> routine above wasn't
thread-safe until C++11.
Imagine what might happen if <code>Logger</code>s constructor takes some time
to initialize the instance.
If a couple of threads then call <code>get_instance</code>, the first thread
might begin the initialization process, making the other thread believe that
the instance has already been intialized.
This other thread might then return a reference to the instance which hasn't
completed its initialization and is most likely unsafe to use.</p>

<p>Since C++11 includes the proposal mentioned above, this routine would indeed
be thread-safe in C++11.
Unfortunately, the compilers shipped with Visual Studio 2012/2013 don't/didn't
implement this particular proposal, which caused me to turn my eyes to
<code>std::call_once</code>, which seems to implement exactly what I
needed.</p>
</div>

[N2660]: http://www.open-std.org/jtc1/sc22/wg21/docs/papers/2008/n2660.htm

The Bug
-------

Unfortunately, matters became a bit more complicated when I tried to have two
singleton classes.
I had `Logger`, like in the example above, and some kind of a "master"
singleton (let's call it `Duke`).
These two classes both inherited from `Singleton`, which I thought was nice.
`Duke`s constructor was heavy and complicated and definetely required some
logging to be done.
OK, I thought, I will simply call `Logger::get_instance` inside `Duke`s
constructor, and everything would be fine.

{% highlight c++ %}
#include <chrono>
#include <thread>

class Logger : public Singleton<Logger>
{
public:
    Logger& operator<<(const char* msg)
    {
        // Actual logging is stripped for brevity
        return *this;
    }

private:
    Logger()
    {
        // Opening log files, etc.
        std::this_thread::sleep_for(std::chrono::seconds{3});
    }

    ~Logger() = default;

    friend class Singleton<Logger>;
};

class Duke : public Singleton<Duke>
{
private:
    Duke()
    {
        Logger::get_instance() << "started Duke's initialization";
        std::this_thread::sleep_for(std::chrono::seconds{10});
        Logger::get_instance() << "finishing Duke's initialization";
    }

    ~Duke() = default;

    friend class Singleton<Duke>;
};
{% endhighlight %}

What would happen if I had two threads, one to do something with the `Duke`
instance, and the other to do something else, logging in process?
Like this:

{% highlight c++ %}
#include <ctime>

#include <iostream>
#include <sstream>
#include <thread>

namespace
{
    void entered(const char* f)
    {
        std::ostringstream oss;
        std::time_t tt = std::time(NULL);
        oss << "Entered " << f << " at " << std::ctime(&tt);
        std::cout << oss.str();
    }

    void exiting(const char* f)
    {
        std::ostringstream oss;
        std::time_t tt = std::time(NULL);
        oss << "Exiting " << f << " at " << std::ctime(&tt);
        std::cout << oss.str();
    }

    void get_logger()
    {
        entered(__FUNCTION__);
        Logger::get_instance() << "got the Logger instance";
        exiting(__FUNCTION__);
    }

    void get_duke()
    {
        entered(__FUNCTION__);
        Duke::get_instance();
        exiting(__FUNCTION__);
    }
}

int main()
{
    std::thread t1(&get_duke);
    std::thread t2(&get_logger);
    t1.join();
    t2.join();
    return 0;
}
{% endhighlight %}

The first thread is supposed to have to total running time of about 13 seconds,
right?
Three seconds to initialize the `Logger` instance and ten to initialize the
`Duke` instance.
The second thread, similarly, is supposed to be executed in about 3 seconds
required for `Logger` initialization.

Weirdly, this program produces the following output when compiled using Visual
Studio 2013's compiler:

    Entered `anonymous-namespace'::get_duke at Fri Jul 03 02:26:16 2015
    Entered `anonymous-namespace'::get_logger at Fri Jul 03 02:26:16 2015
    Exiting `anonymous-namespace'::get_duke at Fri Jul 03 02:26:29 2015
    Exiting `anonymous-namespace'::get_logger at Fri Jul 03 02:26:29 2015

Isn't it wrong that the second thread actually took the same 13 seconds as the
first thread?
Better check with some other compiler in case it was me who made the mistake.
Unfortunately, the program behaves as expected when compiled using GCC's
compiler:

    Entered get_logger at Fri Jul  3 02:27:12 2015
    Entered get_duke at Fri Jul  3 02:27:12 2015
    Exiting get_logger at Fri Jul  3 02:27:15 2015
    Exiting get_duke at Fri Jul  3 02:27:25 2015

So it appears that the implementation of `std::call_once` shipped with Visual
Studio 2012/2013 relies on some kind of a global lock, which causes even the
simple example above to misbehave.

The [complete code] sample to demonstrate the misbehaviour described above can
be found in the blog's repository.

[complete code]: {{ site.github.repository_url }}/tree/gh-pages/src/posts/std_call_once_bug_in_visual_studio_2012_2013

Resolution
----------

So, since I couldn't submit the bug via Visual Studio's [Connect page], I wrote
to Mr. Lavavej directly, not hoping for an answer.
Amazingly, it took him less than a day to reply.
He told me he was planning to overhaul `std::call_once` for Visual Studio 2015.
Meanwhile, I had to stick to something else; I think I either dropped logging
from `Duke`s constructor or initialized all the singleton instances manually
upon program's startup.
In a few months, Mr. Lavavej replied to me (that's professionalism and
responsibility I lack) and wrote that the bug has been fixed in Visual Studio
2015 RTM.
Kudos to the amazing guy!