{"id":76,"date":"2018-03-01T18:00:19","date_gmt":"2018-03-01T18:00:19","guid":{"rendered":"https:\/\/datablog.roman-halliday.com\/?p=76"},"modified":"2018-05-22T19:32:01","modified_gmt":"2018-05-22T19:32:01","slug":"casual-logging","status":"publish","type":"post","link":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/","title":{"rendered":"Casual Logging"},"content":{"rendered":"<p>Often when running a script, or a stored procedure (with many distinct sections) it&#8217;s handy to be able to have the classic &#8220;I&#8217;m here and the time is X&#8221; Logging. I often use this when first looking at monitoring and optimisation of processes.<\/p>\n<p>I thought, for my first post , while I get things a little more organised behind the scenes. I&#8217;ll put something simple that I keep coming back to here, for my own notes as much as anything else.<\/p>\n<h2>Logging in an SQL Script<\/h2>\n<p>The below code spits out to the messages tab in SSMS (or other log locations when automating tasks), the date and time followed by a customisable log message.<\/p>\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"sql\">PRINT CONVERT(VARCHAR(20), GetDate(), 120) + ' - ' + 'Log Message Here';<\/pre>\n<h2>Logging in a stored Procedure<\/h2>\n<p>The below extends the code above for use in a stored procedure. It ads the functionality to output the name of the currently running procedure (using the <code>@@PROCID<\/code>) . This is a handy reference to use as it gets calculated dynamically, and if we copy\/paste between procedures there is no need to remember to change the text containing the procedure name.<\/p>\n<p>I have worked in environments where stored procedures are nested, and make up long running ETL processes. Sometimes this output simplifies seeing the flow of procedures in a complex implementation.<\/p>\n<pre class=\"EnlighterJSRAW\" data-enlighter-language=\"sql\">PRINT CONVERT(VARCHAR(20), GetDate(), 120) + ' : ' + OBJECT_SCHEMA_NAME(@@PROCID) + '.' + OBJECT_NAME(@@PROCID) + 'Log Message Here';<\/pre>\n<p>&nbsp;<\/p>\n","protected":false},"excerpt":{"rendered":"<p>Often when running a script, or a stored procedure (with many distinct sections) it&#8217;s handy to be able to have the classic &#8220;I&#8217;m here and the time is X&#8221; Logging. I often use this when first looking at monitoring and optimisation of processes. I thought, for my first post , while I get things a&hellip;<\/p>\n<p class=\"read-more\"><a class=\"readmore-btn\" href=\"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/\">Read More<span class=\"screen-reader-text\">  Read More<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[3,4],"tags":[],"class_list":["post-76","post","type-post","status-publish","format-standard","hentry","category-databases","category-sql-server"],"yoast_head":"<!-- This site is optimized with the Yoast SEO plugin v27.4 - https:\/\/yoast.com\/product\/yoast-seo-wordpress\/ -->\n<title>Casual Logging - Rows Across The Lake<\/title>\n<meta name=\"description\" content=\"Often when running a script, or a stored procedure (with many distinct sections) it&#039;s handy to be able to have the classic &quot;I&#039;m here and the time is X&quot; Logging. I often use this when first looking at monitoring and optimisation of processes.\u00a0\" \/>\n<meta name=\"robots\" content=\"index, follow, max-snippet:-1, max-image-preview:large, max-video-preview:-1\" \/>\n<link rel=\"canonical\" href=\"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/\" \/>\n<meta property=\"og:locale\" content=\"en_GB\" \/>\n<meta property=\"og:type\" content=\"article\" \/>\n<meta property=\"og:title\" content=\"Casual Logging - Rows Across The Lake\" \/>\n<meta property=\"og:description\" content=\"Often when running a script, or a stored procedure (with many distinct sections) it&#039;s handy to be able to have the classic &quot;I&#039;m here and the time is X&quot; Logging. I often use this when first looking at monitoring and optimisation of processes.\u00a0\" \/>\n<meta property=\"og:url\" content=\"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/\" \/>\n<meta property=\"og:site_name\" content=\"Rows Across The Lake\" \/>\n<meta property=\"article:published_time\" content=\"2018-03-01T18:00:19+00:00\" \/>\n<meta property=\"article:modified_time\" content=\"2018-05-22T19:32:01+00:00\" \/>\n<meta name=\"author\" content=\"david\" \/>\n<meta name=\"twitter:card\" content=\"summary_large_image\" \/>\n<meta name=\"twitter:creator\" content=\"@d_roman_h\" \/>\n<meta name=\"twitter:site\" content=\"@d_roman_h\" \/>\n<meta name=\"twitter:label1\" content=\"Written by\" \/>\n\t<meta name=\"twitter:data1\" content=\"david\" \/>\n\t<meta name=\"twitter:label2\" content=\"Estimated reading time\" \/>\n\t<meta name=\"twitter:data2\" content=\"1 minute\" \/>\n<script type=\"application\/ld+json\" class=\"yoast-schema-graph\">{\"@context\":\"https:\\\/\\\/schema.org\",\"@graph\":[{\"@type\":\"Article\",\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/index.php\\\/2018\\\/03\\\/01\\\/casual-logging\\\/#article\",\"isPartOf\":{\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/index.php\\\/2018\\\/03\\\/01\\\/casual-logging\\\/\"},\"author\":{\"name\":\"david\",\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/#\\\/schema\\\/person\\\/575f96d2590c3085923ff9e1b565748b\"},\"headline\":\"Casual Logging\",\"datePublished\":\"2018-03-01T18:00:19+00:00\",\"dateModified\":\"2018-05-22T19:32:01+00:00\",\"mainEntityOfPage\":{\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/index.php\\\/2018\\\/03\\\/01\\\/casual-logging\\\/\"},\"wordCount\":214,\"commentCount\":1,\"publisher\":{\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/#\\\/schema\\\/person\\\/575f96d2590c3085923ff9e1b565748b\"},\"articleSection\":[\"Databases\",\"SQL Server\"],\"inLanguage\":\"en-GB\",\"potentialAction\":[{\"@type\":\"CommentAction\",\"name\":\"Comment\",\"target\":[\"https:\\\/\\\/datablog.roman-halliday.com\\\/index.php\\\/2018\\\/03\\\/01\\\/casual-logging\\\/#respond\"]}]},{\"@type\":\"WebPage\",\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/index.php\\\/2018\\\/03\\\/01\\\/casual-logging\\\/\",\"url\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/index.php\\\/2018\\\/03\\\/01\\\/casual-logging\\\/\",\"name\":\"Casual Logging - Rows Across The Lake\",\"isPartOf\":{\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/#website\"},\"datePublished\":\"2018-03-01T18:00:19+00:00\",\"dateModified\":\"2018-05-22T19:32:01+00:00\",\"description\":\"Often when running a script, or a stored procedure (with many distinct sections) it's handy to be able to have the classic \\\"I'm here and the time is X\\\" Logging. I often use this when first looking at monitoring and optimisation of processes.\u00a0\",\"breadcrumb\":{\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/index.php\\\/2018\\\/03\\\/01\\\/casual-logging\\\/#breadcrumb\"},\"inLanguage\":\"en-GB\",\"potentialAction\":[{\"@type\":\"ReadAction\",\"target\":[\"https:\\\/\\\/datablog.roman-halliday.com\\\/index.php\\\/2018\\\/03\\\/01\\\/casual-logging\\\/\"]}]},{\"@type\":\"BreadcrumbList\",\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/index.php\\\/2018\\\/03\\\/01\\\/casual-logging\\\/#breadcrumb\",\"itemListElement\":[{\"@type\":\"ListItem\",\"position\":1,\"name\":\"Home\",\"item\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/\"},{\"@type\":\"ListItem\",\"position\":2,\"name\":\"Casual Logging\"}]},{\"@type\":\"WebSite\",\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/#website\",\"url\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/\",\"name\":\"Rows Across The Lake\",\"description\":\"Data &amp; Databases\",\"publisher\":{\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/#\\\/schema\\\/person\\\/575f96d2590c3085923ff9e1b565748b\"},\"potentialAction\":[{\"@type\":\"SearchAction\",\"target\":{\"@type\":\"EntryPoint\",\"urlTemplate\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/?s={search_term_string}\"},\"query-input\":{\"@type\":\"PropertyValueSpecification\",\"valueRequired\":true,\"valueName\":\"search_term_string\"}}],\"inLanguage\":\"en-GB\"},{\"@type\":[\"Person\",\"Organization\"],\"@id\":\"https:\\\/\\\/datablog.roman-halliday.com\\\/#\\\/schema\\\/person\\\/575f96d2590c3085923ff9e1b565748b\",\"name\":\"david\",\"image\":{\"@type\":\"ImageObject\",\"inLanguage\":\"en-GB\",\"@id\":\"https:\\\/\\\/secure.gravatar.com\\\/avatar\\\/acddbc676a1d5c73795edcf0627ee39e5aa947da9033b58373e03d93122cb3b7?s=96&d=mm&r=g\",\"url\":\"https:\\\/\\\/secure.gravatar.com\\\/avatar\\\/acddbc676a1d5c73795edcf0627ee39e5aa947da9033b58373e03d93122cb3b7?s=96&d=mm&r=g\",\"contentUrl\":\"https:\\\/\\\/secure.gravatar.com\\\/avatar\\\/acddbc676a1d5c73795edcf0627ee39e5aa947da9033b58373e03d93122cb3b7?s=96&d=mm&r=g\",\"caption\":\"david\"},\"logo\":{\"@id\":\"https:\\\/\\\/secure.gravatar.com\\\/avatar\\\/acddbc676a1d5c73795edcf0627ee39e5aa947da9033b58373e03d93122cb3b7?s=96&d=mm&r=g\"}}]}<\/script>\n<!-- \/ Yoast SEO plugin. -->","yoast_head_json":{"title":"Casual Logging - Rows Across The Lake","description":"Often when running a script, or a stored procedure (with many distinct sections) it's handy to be able to have the classic \"I'm here and the time is X\" Logging. I often use this when first looking at monitoring and optimisation of processes.\u00a0","robots":{"index":"index","follow":"follow","max-snippet":"max-snippet:-1","max-image-preview":"max-image-preview:large","max-video-preview":"max-video-preview:-1"},"canonical":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/","og_locale":"en_GB","og_type":"article","og_title":"Casual Logging - Rows Across The Lake","og_description":"Often when running a script, or a stored procedure (with many distinct sections) it's handy to be able to have the classic \"I'm here and the time is X\" Logging. I often use this when first looking at monitoring and optimisation of processes.\u00a0","og_url":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/","og_site_name":"Rows Across The Lake","article_published_time":"2018-03-01T18:00:19+00:00","article_modified_time":"2018-05-22T19:32:01+00:00","author":"david","twitter_card":"summary_large_image","twitter_creator":"@d_roman_h","twitter_site":"@d_roman_h","twitter_misc":{"Written by":"david","Estimated reading time":"1 minute"},"schema":{"@context":"https:\/\/schema.org","@graph":[{"@type":"Article","@id":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/#article","isPartOf":{"@id":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/"},"author":{"name":"david","@id":"https:\/\/datablog.roman-halliday.com\/#\/schema\/person\/575f96d2590c3085923ff9e1b565748b"},"headline":"Casual Logging","datePublished":"2018-03-01T18:00:19+00:00","dateModified":"2018-05-22T19:32:01+00:00","mainEntityOfPage":{"@id":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/"},"wordCount":214,"commentCount":1,"publisher":{"@id":"https:\/\/datablog.roman-halliday.com\/#\/schema\/person\/575f96d2590c3085923ff9e1b565748b"},"articleSection":["Databases","SQL Server"],"inLanguage":"en-GB","potentialAction":[{"@type":"CommentAction","name":"Comment","target":["https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/#respond"]}]},{"@type":"WebPage","@id":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/","url":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/","name":"Casual Logging - Rows Across The Lake","isPartOf":{"@id":"https:\/\/datablog.roman-halliday.com\/#website"},"datePublished":"2018-03-01T18:00:19+00:00","dateModified":"2018-05-22T19:32:01+00:00","description":"Often when running a script, or a stored procedure (with many distinct sections) it's handy to be able to have the classic \"I'm here and the time is X\" Logging. I often use this when first looking at monitoring and optimisation of processes.\u00a0","breadcrumb":{"@id":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/#breadcrumb"},"inLanguage":"en-GB","potentialAction":[{"@type":"ReadAction","target":["https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/"]}]},{"@type":"BreadcrumbList","@id":"https:\/\/datablog.roman-halliday.com\/index.php\/2018\/03\/01\/casual-logging\/#breadcrumb","itemListElement":[{"@type":"ListItem","position":1,"name":"Home","item":"https:\/\/datablog.roman-halliday.com\/"},{"@type":"ListItem","position":2,"name":"Casual Logging"}]},{"@type":"WebSite","@id":"https:\/\/datablog.roman-halliday.com\/#website","url":"https:\/\/datablog.roman-halliday.com\/","name":"Rows Across The Lake","description":"Data &amp; Databases","publisher":{"@id":"https:\/\/datablog.roman-halliday.com\/#\/schema\/person\/575f96d2590c3085923ff9e1b565748b"},"potentialAction":[{"@type":"SearchAction","target":{"@type":"EntryPoint","urlTemplate":"https:\/\/datablog.roman-halliday.com\/?s={search_term_string}"},"query-input":{"@type":"PropertyValueSpecification","valueRequired":true,"valueName":"search_term_string"}}],"inLanguage":"en-GB"},{"@type":["Person","Organization"],"@id":"https:\/\/datablog.roman-halliday.com\/#\/schema\/person\/575f96d2590c3085923ff9e1b565748b","name":"david","image":{"@type":"ImageObject","inLanguage":"en-GB","@id":"https:\/\/secure.gravatar.com\/avatar\/acddbc676a1d5c73795edcf0627ee39e5aa947da9033b58373e03d93122cb3b7?s=96&d=mm&r=g","url":"https:\/\/secure.gravatar.com\/avatar\/acddbc676a1d5c73795edcf0627ee39e5aa947da9033b58373e03d93122cb3b7?s=96&d=mm&r=g","contentUrl":"https:\/\/secure.gravatar.com\/avatar\/acddbc676a1d5c73795edcf0627ee39e5aa947da9033b58373e03d93122cb3b7?s=96&d=mm&r=g","caption":"david"},"logo":{"@id":"https:\/\/secure.gravatar.com\/avatar\/acddbc676a1d5c73795edcf0627ee39e5aa947da9033b58373e03d93122cb3b7?s=96&d=mm&r=g"}}]}},"_links":{"self":[{"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/posts\/76","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/comments?post=76"}],"version-history":[{"count":1,"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/posts\/76\/revisions"}],"predecessor-version":[{"id":77,"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/posts\/76\/revisions\/77"}],"wp:attachment":[{"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/media?parent=76"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/categories?post=76"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/datablog.roman-halliday.com\/index.php\/wp-json\/wp\/v2\/tags?post=76"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}