{"id":6463,"date":"2012-09-28T07:00:00","date_gmt":"2012-09-28T07:00:00","guid":{"rendered":"https:\/\/blogs.msdn.microsoft.com\/oldnewthing\/2012\/09\/28\/data-in-crash-dumps-are-not-a-matter-of-opinion\/"},"modified":"2012-09-28T07:00:00","modified_gmt":"2012-09-28T07:00:00","slug":"data-in-crash-dumps-are-not-a-matter-of-opinion","status":"publish","type":"post","link":"https:\/\/devblogs.microsoft.com\/oldnewthing\/20120928-00\/?p=6463","title":{"rendered":"Data in crash dumps are not a matter of opinion"},"content":{"rendered":"

\nA customer reported a problem with the\nSystem­Time­To­Tz­Specific­Local­Time<\/code>\nfunction.\n(Gosh, why couldn’t they have reported a problem with a function with\na shorter name!\nNow I have to type that thing over and over again.)\n<\/p>\n

\n

\nWe’re having a problem with the\nSystem­Time­To­Tz­Specific­Local­Time<\/code>\nfunction.\nWe call it like this:\n<\/p>\n

\ns_pTimeZones->SystemTimeToTzSpecificLocalTime((BYTE)timeZoneId,\n                                 &sysTime, &localTime);\n<\/pre>\n
\nOn some but not all of our machines,\nour program crashes with the following call stack:\n<\/p>\n
\nExceptionAddress: 77d4a0d0 (kernel32!SystemTimeToTzSpecificLocalTime+0x49)\n   ExceptionCode: c0000005 (Access violation)\n  ExceptionFlags: 00000000\nNumberParameters: 2\n   Parameter[0]: 00000000\n   Parameter[1]: 000000ac\nAttempt to read from address 000000ac\nkernel32!SystemTimeToTzSpecificLocalTime+0x49\nContoso!CTimeZones::SystemTimeToTzSpecificLocalTime+0x26\nContoso!CContoso::ResetTimeZone+0xc0\nContoso!ResetTimeZoneThreadProc+0x32\n<\/pre>\n
\nThis problem appears to occur only with the release build;\nthe debug build does not have this problem.\nAny ideas?\n<\/p>\n<\/blockquote>\n
\nNotice that in the line of code the customer provided,\nthey are not<\/i> calling\nSystem­Time­To­Tz­Specific­Local­Time<\/code>;\nthey are instead calling some application-defined method\nwith the same name,\nwhich takes different parameters from the system function.\n<\/p>\n
\nThe customer apologized and included the\nsource file they were using, as well as a crash dump file.\n<\/p>\n
\nvoid CContoso::ResetTimeZone()\n{\n SYSTEMTIME sysTime, localTime;\n GetLastModifiedTime(&sysTime);\n for (int timeZoneId = 1;\n      timeZoneId < MAX_TIME_ZONES;\n      timeZoneId++) {\n  if (!s_pTimeZones->SystemTimeToTzSpecificLocalTime((BYTE)timeZoneId,\n                                  &sysTime, &localTime)) {\n    LOG_ERROR(\"...\");\n    return;\n  }\n  ... do something with localTime ...\n }\n}\nBOOL CTimeZones::SystemTimeToTzSpecificLocalTime(\n    BYTE bTimeZoneID,\n    LPSYSTEMTIME lpUniversalTime,\n    LPSYSTEMTIME lpLocalTime)\n{\n    return ::SystemTimeToTzSpecificLocalTime(\n        &m_pTimeZoneInfo[bTimeZoneID],\n        lpUniversalTime, lpLocalTime);\n}\n<\/pre>\n
\nAccording to the crash dump,\nthe first parameter passed to\nCTime­Zones::System­Time­To­Tz­Specific­Local­Time<\/code>\nwas 1<\/code>,\nand the m_pTimeZoneInfo<\/code> member was nullptr<\/code>.\nAs a result, a bogus non-null pointer was passed as the first\nparameter to\nSystem­Time­To­Tz­Specific­Local­Time<\/code>,\nwhich resulted in a crash when the function tried to dereference it.\n<\/p>\n
\nThis didn’t require any special secret kernel knowledge;\nall I did was look at the stack trace and the value of the\nmember variable.\n<\/p>\n
\nSo far, it was just a case of a lazy developer who didn’t know\nhow to debug their own code.\nBut the reply from the customer was most strange:\n<\/p>\n
\n
\nI don’t think so,\nfor two reasons.\n<\/p>\n
    \n
  1. The exact same build on another machine does not crash,\n    so it must be a machine-specific or OS-specific bug.<\/p>\n
  2. The code in question has not changed in several months,\n    so if the problem were in that code,\n    we would have encountered it much earlier.\n<\/ol>\n<\/blockquote>\n
    \nI was momentarily left speechless by this response.\nIt sounds like the customer simply refuses to believe the\ninformation that’s right there in the crash dump.\n“La la la, I can’t hear you.”\n<\/p>\n
    \nMemory values are not a matter of opinion.\nIf you look in memory and find that the value 5\nis on the stack,\nthen the value 5 is on the stack.\nYou can’t say, “No it isn’t; it’s 6.”\nYou can have different opinions on how the value 5\nended up on the stack, but the fact that the value is 5\nis beyond dispute.\n<\/p>\n
    \nIt’s like a box of cereal that has been spilled on the floor.\nPeople may argue over who spilled the cereal,\nor who placed the box in such a precarious position in the first place,\nbut to take the position\n“There is no cereal on the floor” is a pretty audacious move.\n<\/p>\n
    \nWhether you like it or not, the value is not correct.\nYou can’t deny what’s right there in the dump file.\n(Well, unless you think the dump file itself is incorrect.)\n<\/p>\n
    \nA colleague studied the customer’s code more closely\nand pointed out a race condition where the thread which calls\nCContoso::ResetTimeZone<\/code>\nmay do so before the CTimeZone<\/code> object has\nallocated the m_pTimeZoneInfo<\/code> array.\nAnd it wasn’t anything particularly subtle either.\nIt went like this, in pseudocode:\n<\/p>\n
    \nCreateThread(ResetTimeZoneThreadProc);\ns_pTimeZones = new CTimeZones;\ns_pTimeZones->Initialize();\n\/\/ the CTimeZones::Initialize method allocates m_pTimeZoneInfo\n\/\/ among other things\n<\/pre>\n
    \nThe customer never wrote back once the bug was identified.\nPerhaps the sheer number of impossible things all happening\nat once caused their head to explode.\n<\/p>\n
    \nI discussed this incident later with another colleague,\nwho remarked\n<\/p>\n
    \n
    \nFrequently, some problem X will\noccur, and the people debugging it will say,\n“The only way that problem X to occur is if\nwe are in situation Y,\nbut we know that situation Y is impossible,\nso we didn’t bother investigating that possibility.\nCan you suggest another idea?”\n<\/p>\n
    \nYeah, I can suggest another idea.\n“The computer is always right.”\nYou already saw that problem X occurred.\nIf the only way that problem X can occur is if\nyou are in situation Y,\nthen the first thing you should do is assume that\nyou are in situation Y and work from there.”\n<\/p>\n
    \nTeaching people to follow this simple axiom has\navoid a lot of fruitless misdirected speculative\ndebugging.\nPeople seem hard-wired to\n\nprefer speculation<\/a>,\nthough, and it’s common to slip back into forgetting\nsimple logic.\n<\/p>\n<\/blockquote>\n
    \nTo put it another way:\n<\/p>\n