{"id":4428,"date":"2025-12-18T11:38:52","date_gmt":"2025-12-18T00:38:52","guid":{"rendered":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/?p=4428"},"modified":"2025-12-18T11:41:37","modified_gmt":"2025-12-18T00:41:37","slug":"pop-quiz-what-time-was-it","status":"publish","type":"post","link":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/2025\/12\/18\/pop-quiz-what-time-was-it","title":{"rendered":"Pop quiz: what time was it?"},"content":{"rendered":"\n<p class=\"wp-block-paragraph\">Here&#8217;s a small quiz derived from some incorrect advice from an AI coding assistant. <\/p>\n\n\n\n<pre class=\"wp-block-code\"><code>package main\n\nimport (\n    \"fmt\"\n    \"time\"\n)\n\nfunc main() {\n    fmt.Println(time.Now())\n    defer fmt.Println(time.Now())\n    time.Sleep(10 * time.Second)\n}<\/code><\/pre>\n\n\n\n<p class=\"wp-block-paragraph\">This program prints two timestamps; will they be<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">a. Roughly the same time (ie, the same second)<br>b. Roughly 10 seconds apart<br>c. Something else<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">Answer after the fold<\/p>\n\n\n\n<!--nextpage-->\n\n\n\n<p class=\"wp-block-paragraph\">The answer is a, the timestamps will be approximately the same (modulo the tiny amount of time between two sequential calls to <code>time.Now()<\/code> ). But why?<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">In Go, the arguments to any function are evaluated before the function is called. When applied to <code>defer<\/code> statements, the second <code>time.Now()<\/code> is evaluated immediately, then printed after the delay.<\/p>\n\n\n\n<p class=\"wp-block-paragraph\">To cause the <code>time.Now()<\/code> evaluation to be deferred until the defer block runs, this syntax should be used<\/p>\n\n\n\n<pre class=\"wp-block-code\"><code>defer func() { fmt.Println(time.Now()) }()<\/code><\/pre>\n\n\n\n<p class=\"wp-block-paragraph\">This is a trivial example, but a more common occurrence of this bug can show up in logging and metrics collection, for example<\/p>\n\n\n\n<pre class=\"wp-block-code\"><code>func ServeHTTP(rw http.ResponseWriter, req *http.Request) {\n    fmt.Println(\"request started at\", time.Now())\n    defer fmt.Println(\"request completed at\", time.Now())\n    \/\/ handle request\n}<\/code><\/pre>\n","protected":false},"excerpt":{"rendered":"<p>Here&#8217;s a small quiz derived from some incorrect advice from an AI coding assistant. This program prints two timestamps; will they be a. Roughly the same time (ie, the same second)b. Roughly 10 seconds apartc. Something else Answer after the fold<\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"closed","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"activitypub_content_warning":"","activitypub_content_visibility":"","activitypub_max_image_attachments":3,"activitypub_interaction_policy_quote":"anyone","activitypub_status":"federated","footnotes":""},"categories":[29],"tags":[],"class_list":["post-4428","post","type-post","status-publish","format-standard","hentry","category-golang"],"_links":{"self":[{"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/posts\/4428","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/comments?post=4428"}],"version-history":[{"count":4,"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/posts\/4428\/revisions"}],"predecessor-version":[{"id":4437,"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/posts\/4428\/revisions\/4437"}],"wp:attachment":[{"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/media?parent=4428"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/categories?post=4428"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/dave.cheney.net\/wp-json\/wp\/v2\/tags?post=4428"}],"curies":[{"name":"wp","href":"https:\/\/proxy.goincop1.workers.dev:443\/https\/api.w.org\/{rel}","templated":true}]}}