So, let me tell you about it and may this be a lesson you learn, remember and (unlike me), recognize even when it's in disguise.
So, it all started with good news as I got my first RRD graph served by nginx in my browser. I would have made a screenshot (or just saved the file) but there is nothing really interesting there: just one red dot on a so typical RRD graph. It's funny how technology can fail to be impressive...
I was so happy with my nice graph and started putting more data in the RRD (I am trying to stop my bad habit to talk about RRD database: the D in RRD already means database...) to transform this magnificent dot into a red line. So, I put data in there, wait 5 minutes (the minimum step in my RRD), put some more data, etc. Then, I go back to my favorite browser, find the tab with my red dot and hit the Ctrl+R: blank page. I try a couple of times: same result. Now, I'm really pissed off: I go to my location bar, hit the Enter key and...I got the magnificent red line. At this point I felt like Alexander The Great after undoing the Gordian Knot. And just like him, I still did not know how to untie it. And I hate it when I don't understand things.
So I took a deep breath and tried to confirm the scenario that was causing the problem. So, I tried to run the same request twice with
wget. With both of them, things were fine. So, my browser was doing something special. A little wiresharking later, I found that on the second request my browser was sending an extra header:
Cache-Control:max-age=0So, I tried with
curlI managed to reproduce the problem: I was on the right track. All I had to do was to start nginx under a debugger and see what was the root of all evil. High-level, here is what happens:
- Browser sends its first request.
ngx_http_rrdmodule gets invoked, creates the graph (in a temporary file), creates a buffer pointing to the temporary file.
- nginx sends the content of the temporary file, removes the file and makes all the memory that was used during the processing of this request (it was all allocated from the same pool) available for subsequent processing.
- I hit Ctrl+R
- Browser sends the request with the extra
ngx_http_rrdmodule gets invoked, creates the graph (in a temporary file), creates a buffer pointing to the temporary file but does not initialize it.
- nginx tries to send what is indicated in the buffer but this is corrupted and it ends up sending nothing
Now, why is the initialization problem showing only with the extra header? On the first request, memory is clean (i.e. full of
\x0). The request fills some of this memory with its content, then the buffer allocation uses another "chunk" that has never been used before (and is therefore full of
\x0). So, on the first request everybody is fine. If you replay exactly the same request, you are still fine as you set the same memory bytes as you did on the first run (metaphorically, you are walking in your own steps). The extra header (or actually pretty much anything else) breaks this nice balance and the buffer is allocated slightly higher in memory, ending up in a zone that is not full of
\x0which end up corrupting the buffer logic ad producing the unwanted result.
Now, I told you how stupid of me it was not to initialize correctly the buffer, but nginx API is not really making things easier: it is
ngx_calloc_bufyou should call, not
ngx_alloc_buf. One little 'c' is all the difference there is...
This actually goes back to one of my pet topics when designing an API: if you cannot avoid publishing a "dangerous" API (or function), make sure the name conveys the "dangerosity" of this. In our example, I would have called the functions
ngx_alloc_buf_not_initialized, making the person using this function well aware of what he/she is doing. The first example of this kind of design I saw and loved was the
_dont_implement_Matcher___instead_extend_BaseMatcher_method of the
org.hamcrest.Matcherclass and this was a revelation to me (and not the only one from the guys at org.hamcrest).