{"id":995,"date":"2013-10-25T15:42:00","date_gmt":"2013-10-25T14:42:00","guid":{"rendered":"http:\/\/cyberelk.net\/tim\/?p=995"},"modified":"2014-05-20T09:06:41","modified_gmt":"2014-05-20T08:06:41","slug":"cups-adding-support-for-system-journal","status":"publish","type":"post","link":"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/","title":{"rendered":"CUPS: adding support for system journal"},"content":{"rendered":"

I’ve added a patch to CUPS in Fedora rawhide which uses the system journal for logging. I did this after watching Lennart’s devconf talk<\/a>, which reminded me how awesome the systemd Journal is.<\/p>\n

The changes are very simple at the moment: any log message relating to a particular job has a field “CUPS_JOB_ID” to say which one. Additionally, page log messages include the page number as “CUPS_PAGE_NUMBER”. This support is in rawhide, starting with cups-1.7.0-1.fc21.<\/p>\n

To enable it, adjust \/etc\/cups\/cups-files.conf and set “ErrorLog journal”. You can also set AccessLog and PageLog to “journal”.<\/p>\n

<\/p>\n

Now you’ll be able to fetch the logs relating to a particular job by specifying the job ID, like this:<\/p>\n

$ journalctl CUPS_JOB_ID=13<\/pre>\n
Not sure which job ID you want? You can use tab-completion to help, if you’ll recognise it when you see it. Just press <TAB> twice:<\/p>\n
$ journalctl CUPS_JOB_ID=\r\n10  11  12  13  14  15  16  2   3   4   6   7   8   9<\/pre>\n
Let’s look at job 13:<\/p>\n
$ journalctl CUPS_JOB_ID=13 | fold\r\n-- Logs begin at Tue 2013-10-08 14:21:33 BST, end at Fri 2013-10-25 15:31:49 BST\r\n. --\r\nOct 24 16:53:20 rubik cupsd[13682]: DESKJET-990C twaugh 13 [24\/Oct\/2013:16:53:20\r\n +0100] 1 1 - localhost portrait-a4.pdf - -<\/pre>\n
This job completed normally, so with the default logging level (Info) there is nothing much to say except for the page log, wrapped to fit for this blog entry.<\/p>\n
Jobs that fail get more log messages because the last few filter\/backend messages are stored in the job history, and this history is replayed to the log on failure. Here’s an example of that, trimmed for brevity and again wrapped to fit:<\/p>\n
$ journalctl CUPS_JOB_ID=16 | fold\r\n-- Logs begin at Tue 2013-10-08 14:21:33 BST, end at Fri 2013-10-25 15:31:49 BST\r\n. --\r\nOct 25 15:31:17 rubik cupsd[13682]: HP-Photosmart-5510-series twaugh 16 [25\/Oct\/\r\n2013:15:31:17 +0100] 1 1 - localhost (stdin) - -\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] Job stopped due to filter errors; p\r\nlease consult the error_log file for details.\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] The following messages were recorde\r\nd from 15:31:17 to 15:31:24\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] Adding start banner page \"none\".\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] Queued on \"HP-Photosmart-5510-serie\r\ns\" by \"twaugh\".\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] File of type application\/postscript\r\n queued by \"twaugh\".\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] Adding end banner page \"none\".\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] time-at-processing=1382711477\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] 4 filters for job:\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] pstopdf (application\/postscript to \r\napplication\/pdf, cost 0)\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] pdftopdf (application\/pdf to applic\r\nation\/vnd.cups-pdf, cost 66)\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] gstoraster (application\/vnd.cups-pd\r\nf to application\/vnd.cups-raster, cost 99)\r\nOct 25 15:31:24 rubik cupsd[13682]: [Job 16] hpcups (application\/vnd.cups-raster\r\n to printer\/HP-Photosmart-5510-series, cost 0)\r\n[...]\r\nOct 25 15:31:25 rubik cupsd[13682]: [Job 16] GPL Ghostscript 9.10: Unrecoverable\r\n error, exit code 1\r\nOct 25 15:31:25 rubik cupsd[13682]: [Job 16] PID 3423 (\/usr\/lib\/cups\/filter\/psto\r\npdf) stopped with status 1.\r\nOct 25 15:31:25 rubik cupsd[13682]: [Job 16] Hint: Try setting the LogLevel to \"\r\ndebug\" to find out more.\r\n[...]\r\nOct 25 15:31:25 rubik cupsd[13682]: [Job 16] End of messages\r\nOct 25 15:31:25 rubik cupsd[13682]: [Job 16] printer-state=3(idle)\r\nOct 25 15:31:25 rubik cupsd[13682]: [Job 16] printer-state-message=\"Waiting for \r\nprinter to finish.\"\r\nOct 25 15:31:25 rubik cupsd[13682]: [Job 16] printer-state-reasons=none<\/pre>\n","protected":false},"excerpt":{"rendered":"
I’ve added a patch to CUPS in Fedora rawhide which uses the system journal for logging. I did this after watching Lennart’s devconf talk, which reminded me how awesome the systemd Journal is. The changes are very simple at the moment: any log message relating to a particular job has a field “CUPS_JOB_ID” to say […]<\/p>\n","protected":false},"author":4,"featured_media":0,"comment_status":"closed","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"jetpack_post_was_ever_published":false,"_jetpack_newsletter_access":"","_jetpack_dont_email_post_to_subs":false,"_jetpack_newsletter_tier_id":0,"_jetpack_memberships_contains_paywalled_content":false,"_jetpack_memberships_contains_paid_content":false,"footnotes":"","jetpack_publicize_message":"","jetpack_publicize_feature_enabled":true,"jetpack_social_post_already_shared":true,"jetpack_social_options":{"image_generator_settings":{"template":"highway","default_image_id":0,"font":"","enabled":false},"version":2}},"categories":[3],"tags":[],"class_list":["post-995","post","type-post","status-publish","format-standard","hentry","category-software"],"yoast_head":"\nCUPS: adding support for system journal - PRINT HEAD<\/title>\n<meta name=\"robots\" content=\"index, follow, max-snippet:-1, max-image-preview:large, max-video-preview:-1\" \/>\n<link rel=\"canonical\" href=\"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/\" \/>\n<meta property=\"og:locale\" content=\"en_GB\" \/>\n<meta property=\"og:type\" content=\"article\" \/>\n<meta property=\"og:title\" content=\"CUPS: adding support for system journal - PRINT HEAD\" \/>\n<meta property=\"og:description\" content=\"I’ve added a patch to CUPS in Fedora rawhide which uses the system journal for logging. I did this after watching Lennart’s devconf talk, which reminded me how awesome the systemd Journal is. The changes are very simple at the moment: any log message relating to a particular job has a field “CUPS_JOB_ID” to say […]\" \/>\n<meta property=\"og:url\" content=\"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/\" \/>\n<meta property=\"og:site_name\" content=\"PRINT HEAD\" \/>\n<meta property=\"article:published_time\" content=\"2013-10-25T14:42:00+00:00\" \/>\n<meta property=\"article:modified_time\" content=\"2014-05-20T08:06:41+00:00\" \/>\n<meta name=\"author\" content=\"Tim Waugh\" \/>\n<meta name=\"twitter:card\" content=\"summary_large_image\" \/>\n<meta name=\"twitter:label1\" content=\"Written by\" \/>\n\t<meta name=\"twitter:data1\" content=\"Tim Waugh\" \/>\n\t<meta name=\"twitter:label2\" content=\"Estimated reading time\" \/>\n\t<meta name=\"twitter:data2\" content=\"3 minutes\" \/>\n<script type=\"application\/ld+json\" class=\"yoast-schema-graph\">{\"@context\":\"https:\\\/\\\/schema.org\",\"@graph\":[{\"@type\":\"Article\",\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/2013\\\/10\\\/25\\\/cups-adding-support-for-system-journal\\\/#article\",\"isPartOf\":{\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/2013\\\/10\\\/25\\\/cups-adding-support-for-system-journal\\\/\"},\"author\":{\"name\":\"Tim Waugh\",\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/#\\\/schema\\\/person\\\/23b749f30a67f1b1c6af17024fc94bf6\"},\"headline\":\"CUPS: adding support for system journal\",\"datePublished\":\"2013-10-25T14:42:00+00:00\",\"dateModified\":\"2014-05-20T08:06:41+00:00\",\"mainEntityOfPage\":{\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/2013\\\/10\\\/25\\\/cups-adding-support-for-system-journal\\\/\"},\"wordCount\":231,\"publisher\":{\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/#\\\/schema\\\/person\\\/23b749f30a67f1b1c6af17024fc94bf6\"},\"articleSection\":[\"Software\"],\"inLanguage\":\"en-GB\"},{\"@type\":\"WebPage\",\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/2013\\\/10\\\/25\\\/cups-adding-support-for-system-journal\\\/\",\"url\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/2013\\\/10\\\/25\\\/cups-adding-support-for-system-journal\\\/\",\"name\":\"CUPS: adding support for system journal - PRINT HEAD\",\"isPartOf\":{\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/#website\"},\"datePublished\":\"2013-10-25T14:42:00+00:00\",\"dateModified\":\"2014-05-20T08:06:41+00:00\",\"breadcrumb\":{\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/2013\\\/10\\\/25\\\/cups-adding-support-for-system-journal\\\/#breadcrumb\"},\"inLanguage\":\"en-GB\",\"potentialAction\":[{\"@type\":\"ReadAction\",\"target\":[\"https:\\\/\\\/cyberelk.net\\\/tim\\\/2013\\\/10\\\/25\\\/cups-adding-support-for-system-journal\\\/\"]}]},{\"@type\":\"BreadcrumbList\",\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/2013\\\/10\\\/25\\\/cups-adding-support-for-system-journal\\\/#breadcrumb\",\"itemListElement\":[{\"@type\":\"ListItem\",\"position\":1,\"name\":\"Home\",\"item\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/\"},{\"@type\":\"ListItem\",\"position\":2,\"name\":\"CUPS: adding support for system journal\"}]},{\"@type\":\"WebSite\",\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/#website\",\"url\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/\",\"name\":\"PRINT HEAD\",\"description\":\"\",\"publisher\":{\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/#\\\/schema\\\/person\\\/23b749f30a67f1b1c6af17024fc94bf6\"},\"potentialAction\":[{\"@type\":\"SearchAction\",\"target\":{\"@type\":\"EntryPoint\",\"urlTemplate\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/?s={search_term_string}\"},\"query-input\":{\"@type\":\"PropertyValueSpecification\",\"valueRequired\":true,\"valueName\":\"search_term_string\"}}],\"inLanguage\":\"en-GB\"},{\"@type\":[\"Person\",\"Organization\"],\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/#\\\/schema\\\/person\\\/23b749f30a67f1b1c6af17024fc94bf6\",\"name\":\"Tim Waugh\",\"image\":{\"@type\":\"ImageObject\",\"inLanguage\":\"en-GB\",\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/wp-content\\\/uploads\\\/2023\\\/01\\\/printhead.png\",\"url\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/wp-content\\\/uploads\\\/2023\\\/01\\\/printhead.png\",\"contentUrl\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/wp-content\\\/uploads\\\/2023\\\/01\\\/printhead.png\",\"width\":731,\"height\":140,\"caption\":\"Tim Waugh\"},\"logo\":{\"@id\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/wp-content\\\/uploads\\\/2023\\\/01\\\/printhead.png\"},\"sameAs\":[\"http:\\\/\\\/cyberelk.net\\\/tim\"],\"url\":\"https:\\\/\\\/cyberelk.net\\\/tim\\\/author\\\/twaugh\\\/\"}]}<\/script>\n<!-- \/ Yoast SEO plugin. -->","yoast_head_json":{"title":"CUPS: adding support for system journal - PRINT HEAD","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:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/","og_locale":"en_GB","og_type":"article","og_title":"CUPS: adding support for system journal - PRINT HEAD","og_description":"I’ve added a patch to CUPS in Fedora rawhide which uses the system journal for logging. I did this after watching Lennart’s devconf talk, which reminded me how awesome the systemd Journal is. The changes are very simple at the moment: any log message relating to a particular job has a field “CUPS_JOB_ID” to say […]","og_url":"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/","og_site_name":"PRINT HEAD","article_published_time":"2013-10-25T14:42:00+00:00","article_modified_time":"2014-05-20T08:06:41+00:00","author":"Tim Waugh","twitter_card":"summary_large_image","twitter_misc":{"Written by":"Tim Waugh","Estimated reading time":"3 minutes"},"schema":{"@context":"https:\/\/schema.org","@graph":[{"@type":"Article","@id":"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/#article","isPartOf":{"@id":"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/"},"author":{"name":"Tim Waugh","@id":"https:\/\/cyberelk.net\/tim\/#\/schema\/person\/23b749f30a67f1b1c6af17024fc94bf6"},"headline":"CUPS: adding support for system journal","datePublished":"2013-10-25T14:42:00+00:00","dateModified":"2014-05-20T08:06:41+00:00","mainEntityOfPage":{"@id":"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/"},"wordCount":231,"publisher":{"@id":"https:\/\/cyberelk.net\/tim\/#\/schema\/person\/23b749f30a67f1b1c6af17024fc94bf6"},"articleSection":["Software"],"inLanguage":"en-GB"},{"@type":"WebPage","@id":"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/","url":"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/","name":"CUPS: adding support for system journal - PRINT HEAD","isPartOf":{"@id":"https:\/\/cyberelk.net\/tim\/#website"},"datePublished":"2013-10-25T14:42:00+00:00","dateModified":"2014-05-20T08:06:41+00:00","breadcrumb":{"@id":"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/#breadcrumb"},"inLanguage":"en-GB","potentialAction":[{"@type":"ReadAction","target":["https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/"]}]},{"@type":"BreadcrumbList","@id":"https:\/\/cyberelk.net\/tim\/2013\/10\/25\/cups-adding-support-for-system-journal\/#breadcrumb","itemListElement":[{"@type":"ListItem","position":1,"name":"Home","item":"https:\/\/cyberelk.net\/tim\/"},{"@type":"ListItem","position":2,"name":"CUPS: adding support for system journal"}]},{"@type":"WebSite","@id":"https:\/\/cyberelk.net\/tim\/#website","url":"https:\/\/cyberelk.net\/tim\/","name":"PRINT HEAD","description":"","publisher":{"@id":"https:\/\/cyberelk.net\/tim\/#\/schema\/person\/23b749f30a67f1b1c6af17024fc94bf6"},"potentialAction":[{"@type":"SearchAction","target":{"@type":"EntryPoint","urlTemplate":"https:\/\/cyberelk.net\/tim\/?s={search_term_string}"},"query-input":{"@type":"PropertyValueSpecification","valueRequired":true,"valueName":"search_term_string"}}],"inLanguage":"en-GB"},{"@type":["Person","Organization"],"@id":"https:\/\/cyberelk.net\/tim\/#\/schema\/person\/23b749f30a67f1b1c6af17024fc94bf6","name":"Tim Waugh","image":{"@type":"ImageObject","inLanguage":"en-GB","@id":"https:\/\/cyberelk.net\/tim\/wp-content\/uploads\/2023\/01\/printhead.png","url":"https:\/\/cyberelk.net\/tim\/wp-content\/uploads\/2023\/01\/printhead.png","contentUrl":"https:\/\/cyberelk.net\/tim\/wp-content\/uploads\/2023\/01\/printhead.png","width":731,"height":140,"caption":"Tim Waugh"},"logo":{"@id":"https:\/\/cyberelk.net\/tim\/wp-content\/uploads\/2023\/01\/printhead.png"},"sameAs":["http:\/\/cyberelk.net\/tim"],"url":"https:\/\/cyberelk.net\/tim\/author\/twaugh\/"}]}},"jetpack_publicize_connections":[],"jetpack_featured_media_url":"","jetpack_sharing_enabled":true,"jetpack_shortlink":"https:\/\/wp.me\/pnnS2-g3","_links":{"self":[{"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/posts\/995","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/users\/4"}],"replies":[{"embeddable":true,"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/comments?post=995"}],"version-history":[{"count":6,"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/posts\/995\/revisions"}],"predecessor-version":[{"id":1001,"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/posts\/995\/revisions\/1001"}],"wp:attachment":[{"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/media?parent=995"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/categories?post=995"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/cyberelk.net\/tim\/wp-json\/wp\/v2\/tags?post=995"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}