Project

General

Profile

Actions

action #113312

closed

passwords (again) showing up in logs, this time in video_base size:M

Added by okurz over 2 years ago. Updated over 2 years ago.

Status:
Resolved
Priority:
High
Assignee:
Category:
Regressions/Crashes
Target version:
Start date:
2022-07-06
Due date:
% Done:

0%

Estimated time:

Description

Observation

https://openqa.opensuse.org/tests/2453477/logfile?filename=autoinst-log.txt
shows

susedistribution::handle_password_prompt -> lib/susedistribution.pm:70 called testapi::type_password
[2022-07-06T12:06:05.534656+02:00] [debug] <<< testapi::type_string(string="[masked]", max_interval=100, wait_screen_change=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2022-07-06T12:06:05.535894+02:00] [debug] <<< consoles::video_base::type_string(max_interval=100, cmd="backend_type_string", json_cmd_token="HWQIViIt", text="nots3cr3t")

I guess it should be obvious that this is not intended this way. There had been multiple people working on hiding passwords but apparently it only gets worse. Let's be better :)

Acceptance criteria

  • AC1: No log messages show the password, duh, in particular no password from consoles::video_base::type_string

Suggestions

  • Check why we even have "testapi::type_string" and "video_base::type_string" and repeat the log message in both. Maybe we can avoid the log in consoles::video_base::type_string
  • Check unit tests if maybe we just look at the log message of testapi::type_string but not video_base
  • Try to reproduce locally and use git bisect to find the culprit introducing the regression: Already clear. commit 4e66dcc0 introduced this:
(cfconrad/log_call_secrets)
Author: Clemens Famulla-Conrad <cfamullaconrad@suse.de>
Date:   Wed May 18 10:50:07 2022 +0200

    bmwqemu: Hide secrets on log output with log_call()

    Parse given parameters for `-masked => <string>` and replace
    all occurrence from the given `<string>` with `[masked]` in the
    log output.

diff --git a/consoles/video_base.pm b/consoles/video_base.pm
index 6dba68d4..549f12dc 100644
--- a/consoles/video_base.pm
+++ b/consoles/video_base.pm
@@ -30,6 +30,8 @@ sub _typing_limit () { $bmwqemu::vars{TYPING_LIMIT} // TYPING_LIMIT_DEFAULT || 1
 sub send_key_event ($key, $press_release_delay) { }

 sub type_string ($self, $args) {
+    bmwqemu::log_call(%$args, $args->{secret} ? (-masked => $args->{text}) : ());

Previous PR URLs

Actions #1

Updated by livdywan over 2 years ago

  • Subject changed from passwords (again) showing up in logs, this time in video_base to passwords (again) showing up in logs, this time in video_base size:M
  • Description updated (diff)
  • Status changed from New to Workable
Actions #2

Updated by okurz over 2 years ago

  • Due date set to 2022-07-22
  • Status changed from Workable to Feedback
  • Assignee set to okurz
Actions #3

Updated by okurz over 2 years ago

https://github.com/os-autoinst/os-autoinst/pull/2110

I agree with @kalikiana. The current PR is an improvement and I will not delete the serial+ssh backend log messages but maybe we can improve that later on.

Actions #4

Updated by okurz over 2 years ago

  • Due date deleted (2022-07-22)
  • Status changed from Feedback to Resolved

tests look good, e.g. from https://openqa.opensuse.org/tests/2462409/logfile?filename=autoinst-log.txt

[2022-07-11T11:30:28.393866+02:00] [debug] <<< testapi::assert_screen(mustmatch="password-prompt", timeout=60)
[2022-07-11T11:30:29.218881+02:00] [debug] >>> testapi::_handle_found_needle: found password-prompt-20160812, similarity 1.00 @ 0/112
[2022-07-11T11:30:29.219152+02:00] [debug] tests/console/system_prepare.pm:31 called testapi::select_console -> lib/susedistribution.pm:797 called susedistribution::handle_password_prompt -> lib/susedistribution.pm:70 called testapi::type_password
[2022-07-11T11:30:29.219368+02:00] [debug] <<< testapi::type_string(string="[masked]", max_interval=100, wait_screen_change=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2022-07-11T11:30:30.426337+02:00] [debug] tests/console/system_prepare.pm:31 called testapi::select_console -> lib/susedistribution.pm:797 called susedistribution::handle_password_prompt -> lib/susedistribution.pm:72 called testapi::send_key
[2022-07-11T11:30:30.426599+02:00] [debug] <<< testapi::send_key(key="ret", do_wait=0, wait_screen_change=0)
[2022-07-11T11:30:30.695168+02:00] [debug] tests/console/system_prepare.pm:31 called testapi::select_console -> lib/susedistribution.pm:808 called testapi::assert_screen
[2022-07-11T11:30:30.695407+02:00] [debug] <<< testapi::assert_screen(mustmatch="text-logged-in-root", timeout=60)
Actions

Also available in: Atom PDF