{"id":91501,"date":"2015-09-28T07:00:00","date_gmt":"2015-09-28T21:00:00","guid":{"rendered":"https:\/\/blogs.msdn.microsoft.com\/oldnewthing\/20150928-00\/?p=91501\/"},"modified":"2019-03-13T12:19:59","modified_gmt":"2019-03-13T19:19:59","slug":"20150928-00","status":"publish","type":"post","link":"https:\/\/devblogs.microsoft.com\/oldnewthing\/20150928-00\/?p=91501","title":{"rendered":"What happens to lost timer messages if I don’t process them fast enough?"},"content":{"rendered":"

Some time ago, I noted that if your WM_TIMER<\/code> handler takes longer than the timer period, your queue will not fill up with WM_TIMER<\/code> messages<\/a>. The WM_TIMER<\/code> message is generated on demand, and if your handler doesn’t check for messages, then there is no demand for timer messages. But what happens when your thread finally starts processing messages again? What happens to the timers that elapsed while you were busy? Do they accumulate? <\/p>\n

Here’s a sketch of how timers work. (Note that the timers under discussion here are the timers set by the Set­Timer<\/code> function.) <\/p>\n

When a timer is created, it is initially not ready<\/i>. <\/p>\n

Every n<\/var> milliseconds (where n<\/var> is the period of the timer), the timer is marked ready<\/i>. This is done regardless of the state of the UI thread. Note that ready<\/i> is a flag, not a counter. If the timer is already ready, then it stays ready; there is no such thing as “double ready”. The QS_TIMER<\/code> flag is set on the queue state, indicating that there is now a pending timer for the thread. This in turn may cause a function like Get­Message<\/code> or Msg­Wait­For­Multiple­Objects<\/code> to wake up. <\/p>\n

When the appropriate conditions are met (as discussed earlier<\/a>), the window manager checks whether there are any timers for the thread that are marked ready<\/i>. If so, then the corresponding WM_TIMER<\/code> message is generated and the ready<\/i> flag is cleared. <\/p>\n

Let’s illustrate this with our scratch program<\/a>. Make the following changes: <\/p>\n

\n#include <strsafe.h>\n\nDWORD g_tmStart;\n\nvoid SquirtTime()\n{\n TCHAR sz[256];\n StringCchPrintf(sz, 256, \"%d\\r\\n\", GetTickCount() - g_tmStart);\n OutputDebugString(sz);\n}\n<\/pre>\n
This adds a function that prints the number of milliseconds which have elapsed since g_tmStart<\/code>. Note that we use simple subtraction and rely on unsigned arithmetic to handle timer rollover issues. <\/p>\n
\nvoid CALLBACK OnTimer(HWND hwnd, UINT, UINT_PTR, DWORD)\n{\n SquirtTime();\n}\n<\/pre>\n
Our timer tick handler merely prints the elapsed time to the debugger. <\/p>\n
\nBOOL\nOnCreate(HWND hwnd, LPCREATESTRUCT lpcs)\n{\n g_tmStart = GetTickCount();\n SetTimer(hwnd, 1, 500, OnTimer);\n Sleep(1750);<\/font>\n return TRUE;\n}\n<\/pre>\n
Finally, we create a 500ms timer on our window, but we also intentionally stall the thread for 1750ms. <\/p>\n
Can you predict the output of this program? <\/p>\n
Here’s what I got when I ran the program:<\/p>\n
\n1797\n2000\n2500\n3000\n3500\n4000\n4500\n...\n<\/pre>\n
Let’s see if we can explain it. <\/p>\n
Since the timer is set to fire at 500ms intervals, every 500ms, the timer gets marked ready. <\/p>\n
    \n
  • At T<\/var> = 500ms, the timer is marked ready. \n
  • At T<\/var> = 1000ms, the timer is marked ready.     This is redundant, since the timer is already ready. \n
  • At T<\/var> = 1500ms, the timer is marked ready.     Again, this is redundant. \n
  • At T<\/var> = 1750ms, the program finally wakes up     from its Sleep<\/code> and eventually gets around     to processing messages. \n
  • Hey look, there is a ready timer, so we generate a     WM_TIMER<\/code> message and clear the ready<\/i>     flag. \n
  • At T<\/var> = 1797ms, the timer message is processed. \n
  • The program returns to its message loop, where there are no     further messages to process, so it sits and waits. \n
  • At T<\/var> = 2000ms, the timer is marked ready.     This causes the Get­Message<\/code> to wake up     generate a     WM_TIMER<\/code> message and clear the ready<\/i>     flag. \n
  • At T<\/var> = 2000ms, the timer message is processed. \n
  • At T<\/var> = 2500ms, the timer is marked ready.     This causes the Get­Message<\/code> to wake up     generate a     WM_TIMER<\/code> message and clear the ready<\/i>     flag. \n
  • At T<\/var> = 2500ms, the timer message is processed. \n
  • And so on, with a new timer message every 500ms     that is processed immediately. <\/ul>\n
    Observe that when the program begins processing messages at T<\/var> = 1750ms, it receives only one timer message right away, even though three timer periods have elapsed. <\/p>\n
    I guess another way of looking at this is to think of your timer as setting a frame rate. If your thread is busy when it’s time to render the next frame, then the next frame is late. And if your thread is really busy, it may drop frames entirely. <\/p>\n","protected":false},"excerpt":{"rendered":"
    They never existed.<\/p>\n","protected":false},"author":1069,"featured_media":111744,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[1],"tags":[25],"class_list":["post-91501","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-oldnewthing","tag-code"],"acf":[],"blog_post_summary":"
    They never existed.<\/p>\n","_links":{"self":[{"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/posts\/91501","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/users\/1069"}],"replies":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/comments?post=91501"}],"version-history":[{"count":0,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/posts\/91501\/revisions"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/media\/111744"}],"wp:attachment":[{"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/media?parent=91501"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/categories?post=91501"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/oldnewthing\/wp-json\/wp\/v2\/tags?post=91501"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}