Enhance Logging for CUPS |
||||
Issue descriptionWe need more logging if we're going to diagnose issues in the field. Survey of options: go/cros-printer-logs Conclusion is to enhance the logs that CUPS writes to /var/log/messages go/moar-cups-logs
,
May 16 2017
+afakhry@ - Following up from our conversation yesterday, could you check to see if the UUIDs in the attached sample log file are caught by the current script that redacts identifying data? Thanks!!
,
May 16 2017
Re: weifangsun, Please find below the output the log you sent after it passes through the anonymizer. As you can see, the only thing that was scrubbed is the IP address in the last line "Accepted keyboard-interactive/pam for root from ...". Please let me know if there are other things that need to be scrubbed as well, and if you could also find out whether it has a standard format to help in the detection, that would be very helpful! Thanks! 2017-05-10T17:23:37.857344-07:00 WARNING minijail0[3378]: libminijail[3378]: allowing syscall: connect 2017-05-10T17:23:37.857374-07:00 WARNING minijail0[3378]: libminijail[3378]: allowing syscall: sendto 2017-05-10T17:23:37.864055-07:00 WARNING cupsd[3379]: libminijail[1]: logging seccomp filter failures 2017-05-10T17:23:37.885739-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /admin/ HTTP/1.1" 401 242 CUPS-Add-Modify-Printer successful-ok 2017-05-10T17:23:37.888466-07:00 INFO cupsd[3379]: REQUEST localhost - lpadmin "POST /admin/ HTTP/1.1" 200 242 CUPS-Add-Modify-Printer successful-ok 2017-05-10T17:23:37.897201-07:00 INFO cupsd[3379]: REQUEST localhost - lpadmin "POST /admin/ HTTP/1.1" 200 2993 CUPS-Add-Modify-Printer successful-ok 2017-05-10T17:23:40.229741-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /printers/cb738a9f-6433-4d95-a81e-94e4ae0ed30b HTTP/1.1" 200 291 Create-Job successful-ok 2017-05-10T17:23:40.731782-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /printers/cb738a9f-6433-4d95-a81e-94e4ae0ed30b HTTP/1.1" 200 20632 Send-Document successful-ok 2017-05-10T17:23:40.735930-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /printers/cb738a9f-6433-4d95-a81e-94e4ae0ed30b HTTP/1.1" 200 199 Close-Job successful-ok 2017-05-10T17:24:10.638461-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /admin/ HTTP/1.1" 401 242 CUPS-Add-Modify-Printer successful-ok 2017-05-10T17:24:10.641822-07:00 INFO cupsd[3379]: REQUEST localhost - lpadmin "POST /admin/ HTTP/1.1" 200 242 CUPS-Add-Modify-Printer successful-ok 2017-05-10T17:24:10.652958-07:00 INFO cupsd[3379]: REQUEST localhost - lpadmin "POST /admin/ HTTP/1.1" 200 2993 CUPS-Add-Modify-Printer successful-ok 2017-05-10T17:24:14.611159-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /admin/ HTTP/1.1" 401 242 CUPS-Add-Modify-Printer successful-ok 2017-05-10T17:24:14.621139-07:00 INFO cupsd[3379]: REQUEST localhost - lpadmin "POST /admin/ HTTP/1.1" 200 242 CUPS-Add-Modify-Printer successful-ok 2017-05-10T17:24:14.653131-07:00 INFO cupsd[3379]: REQUEST localhost - lpadmin "POST /admin/ HTTP/1.1" 200 4161 CUPS-Add-Modify-Printer successful-ok 2017-05-10T17:24:16.914999-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /printers/d17188da-9cd3-44f4-b148-3e1d748a3b0f HTTP/1.1" 200 286 Create-Job successful-ok 2017-05-10T17:24:17.417747-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /printers/d17188da-9cd3-44f4-b148-3e1d748a3b0f HTTP/1.1" 200 20627 Send-Document successful-ok 2017-05-10T17:24:17.423872-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /printers/d17188da-9cd3-44f4-b148-3e1d748a3b0f HTTP/1.1" 200 199 Close-Job successful-ok 2017-05-10T17:24:24.461897-07:00 ERR cupsd[3379]: [Job 4] The printer is not responding. 2017-05-10T17:24:37.816417-07:00 INFO cupsd[3379]: REQUEST localhost - - "POST /jobs/ HTTP/1.1" 200 203 Cancel-Job successful-ok 2017-05-10T17:25:26.373141-07:00 INFO sshd[3484]: Accepted keyboard-interactive/pam for root from <IPv4: 1>17 port 59998 ssh2
,
May 16 2017
The formats are UUIDs. The format is xxxxxxxx-xxxx-Mxxx-Nxxx-xxxxxxxxxxxx where x is a hex-digit, M is the UUID version and N is the variant number. It's 5 groups of characters with 36 total characters including the 4 hyphens. The format is 8-4-4-4-12. Source: https://en.wikipedia.org/wiki/Universally_unique_identifier Governing RFC https://tools.ietf.org/html/rfc4122
,
May 24 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/8fb8758cdb771ccc13116509f024be979c640889 commit 8fb8758cdb771ccc13116509f024be979c640889 Author: Sean Kau <skau@chromium.org> Date: Wed May 24 06:59:28 2017 [net-print/cups] Log desired messages at notice Add log messages for filter names and exit codes as well as logging printer operations. This CL changes the cupsd LogLevel from warn to notice, logging additional printer status. Additionally, it relablels logs for filters at CUPSD_LOG_NOTICE so we can diagnose printing issues reported through feedback. In total, we should log about 10 lines per print job. Previously, nothing was logged if a job was successful. BUG= chromium:721115 TEST=Attempt print with a working configuration and a brokend configuration then examined /var/log/messages to verify the correct content was included. Change-Id: Ie9301c8f8ae655b6e8d961ab102ea198c8f3708d Reviewed-on: https://chromium-review.googlesource.com/503089 Commit-Ready: Sean Kau <skau@chromium.org> Tested-by: Sean Kau <skau@chromium.org> Reviewed-by: Andrew de los Reyes <adlr@chromium.org> [modify] https://crrev.com/8fb8758cdb771ccc13116509f024be979c640889/net-print/cups/files/cupsd.conf [add] https://crrev.com/8fb8758cdb771ccc13116509f024be979c640889/net-print/cups/files/cups-2.1.4-raise-log-level-for-desired-features.patch [rename] https://crrev.com/8fb8758cdb771ccc13116509f024be979c640889/net-print/cups/cups-2.1.4-r17.ebuild [modify] https://crrev.com/8fb8758cdb771ccc13116509f024be979c640889/net-print/cups/cups-2.1.4.ebuild
,
May 24 2017
Thanks both!! afakhry@ - Are you able to add scrubbing for the UUIDs based on the format guidance that skau@ has provided? I think it's probably safer to remove them. Let me know if I should log another bug for that work to track!
,
May 24 2017
Yes, I can handle this. I can either use this same bug, or a new bug blocking this one, whatever works for you. Is there a time frame for this issue?
,
May 24 2017
Thanks! Let's use this bug to track. We are planning to include these logs for M60.
,
May 24 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/5a59f95a0fcbaa5976fa7e7247f77f430d9d041a commit 5a59f95a0fcbaa5976fa7e7247f77f430d9d041a Author: afakhry <afakhry@chromium.org> Date: Wed May 24 21:04:26 2017 Anonymize UUIDs Add a pattern to the anonymizer tool to catch and anonymize Universal Unique Identidiers (UUIDs). BUG= 721115 TEST=components_unittests --gtest_filter=AnonymizerToolTest.AnonymizeCustomPatterns Review-Url: https://codereview.chromium.org/2905723002 Cr-Commit-Position: refs/heads/master@{#474420} [modify] https://crrev.com/5a59f95a0fcbaa5976fa7e7247f77f430d9d041a/components/feedback/anonymizer_tool.cc [modify] https://crrev.com/5a59f95a0fcbaa5976fa7e7247f77f430d9d041a/components/feedback/anonymizer_tool_unittest.cc
,
May 24 2017
Re: weifangsun@, Done.
,
May 25 2017
afakhry@ - Thanks so much for the quick turn around!!
,
Jun 8 2017
,
Jan 22 2018
|
||||
►
Sign in to add a comment |
||||
Comment 1 by skau@chromium.org
, May 10 2017