pkg/importer: Increase number of nbdkit lines logged

[rwmjones]

30 is far too small. For "chatty" plugins like VDDK many more debugging lines will be printed for simple open calls. For debugging it is vital that we do not lose this information. Ideally I would set this to infinity.

Related: https://issues.redhat.com/browse/CNV-44894

Release note:

VDDK datasource: Increase number of nbdkit lines logged

CC @mrnold

[kubevirt-bot]

Hi @rwmjones. Thanks for your PR.

PRs from untrusted users cannot be marked as trusted with /ok-to-test in this repo meaning untrusted PR authors can never trigger tests themselves. Collaborators can still trigger tests on the PR using /test all.

I understand the commands that are listed here.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

[arnongilboa]

/lgtm

[coveralls]

coverage: 59.172% (+0.008%) from 59.164%
when pulling a9f2836 on rwmjones:nbdkit-more-logs
into 1ac6087 on kubevirt:main.

[akalenyu]

Looks good, if you want, you have the nbdkit cmd stdout in output *bufio.Reader

containerized-data-importer/pkg/importer/vddk-datasource_amd64.go

Line 146 in a9f2836

func (watcher NbdKitLogWatcherVddk) Start(output *bufio.Reader) {

so you could just write the entire thing into /tmp/nbdkit.log by dropping

containerized-data-importer/pkg/image/nbdkit.go

Lines 293 to 296 in a9f2836

	_, err = f.WriteString(logLine)
	if err != nil {
	klog.Errorf("failed to write log line; %v", err)
	}

in the scanner loop
(unless theres some implication in doing that)

[mrnold]

Looks good, if you want, you have the nbdkit cmd stdout in output *bufio.Reader

containerized-data-importer/pkg/importer/vddk-datasource_amd64.go

Line 146 in a9f2836

func (watcher NbdKitLogWatcherVddk) Start(output *bufio.Reader) {

so you could just write the entire thing into /tmp/nbdkit.log by dropping

containerized-data-importer/pkg/image/nbdkit.go

Lines 293 to 296 in a9f2836

	_, err = f.WriteString(logLine)
	if err != nil {
	klog.Errorf("failed to write log line; %v", err)
	}

in the scanner loop
(unless theres some implication in doing that)

This is probably the way to go, to see everything from nbdkit/VDDK get logged. I think there is a password printed in plain text in there somewhere though, it might be a good idea to filter that out.

[rwmjones]

I think there is a password printed in plain text in there somewhere though, it might be a good idea to filter that out.

The password is passed to nbdkit directly on the command line here:

containerized-data-importer/pkg/image/nbdkit.go

Line 96 in 1ac6087

pluginArgs = append(pluginArgs, "password="+password)

This is bad in several ways:

• You expose the password to commands like ps (assuming someone has a shell inside the container).
• It gets printed in nbdkit debug output, which you're filtering.
• If the password starts with - or + then you likely have a security hole.

You can avoid all that by writing the password into a temporary file (ensure that the file is unreadable by other), and then passing password=+/path/to/temp/file on the command line instead. If you don't want the temp file, you can also use inherited file descriptors and pipes but it's a bit harder to implement.

More details here (scroll down a bit to where it talks about the password parameter):

https://libguestfs.org/nbdkit-vddk-plugin.1.html#PARAMETERS

[rwmjones]

The test fails seem unrelated ...?

[rwmjones]

/test pull-containerized-data-importer-e2e-hpp-latest

[kubevirt-bot]

@rwmjones: Cannot trigger testing until a trusted user reviews the PR and leaves an /ok-to-test message.

In response to this:

/test pull-containerized-data-importer-e2e-hpp-latest

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

[akalenyu]

The test fails seem unrelated ...?

correct:
#3024

/test pull-containerized-data-importer-e2e-hpp-latest

[akalenyu]

/test pull-containerized-data-importer-e2e-ceph

[akalenyu]

Looks good, if you want, you have the nbdkit cmd stdout in output *bufio.Reader

containerized-data-importer/pkg/importer/vddk-datasource_amd64.go

Line 146 in a9f2836

func (watcher NbdKitLogWatcherVddk) Start(output *bufio.Reader) {

so you could just write the entire thing into /tmp/nbdkit.log by dropping

containerized-data-importer/pkg/image/nbdkit.go

Lines 293 to 296 in a9f2836

	_, err = f.WriteString(logLine)
	if err != nil {
	klog.Errorf("failed to write log line; %v", err)
	}

in the scanner loop
(unless theres some implication in doing that)

Let me know if you plan to take this suggestion

[rwmjones]

Let me know if you plan to take this suggestion

I didn't really understand what exactly was meant.

For the immediate customer bug we're facing, getting more log lines out from the customer's container is the most important thing here.

[akalenyu]

Let me know if you plan to take this suggestion

I didn't really understand what exactly was meant.

For the immediate customer bug we're facing, getting more log lines out from the customer's container is the most important thing here.

I am suggesting to dump the entire log into a file

[rwmjones]

How can we see the log then? Currently the customer runs oc logs <podname> and they can see (unfortunately only) 30 lines of the log.

[arnongilboa]

Let me know if you plan to take this suggestion

I didn't really understand what exactly was meant.
For the immediate customer bug we're facing, getting more log lines out from the customer's container is the most important thing here.

I am suggesting to dump the entire log into a file

You can't ssh the pod if it failed/completed, so how would you get the nbd log if pod fails too quick? we can keep a debug pod running but not sure that's the best way to go. I guess that's the reason we put it in the pod log.

[akalenyu]

How can we see the log then? Currently the customer runs oc logs <podname> and they can see (unfortunately only) 30 lines of the log.

You would have to watch that file in the container. Let me know if you want this merged as is

[rwmjones]

@mrnold If you're happy with this, then so I am. It's a minimal change to improve the situation and collect the logs, perhaps not the long term final fix.

The password issue noted above is also quite important. I may have a go at fixing that if I get time today.

[akalenyu]

/approve
/hold

@mrnold unhold when ready

[kubevirt-bot]

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: akalenyu

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

• OWNERS [akalenyu]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

[mrnold]

/unhold

I think it's fine to keep this pull request to the one small change, and implement the other suggestions separately.

[fabiand]

@akalenyu can we get this change backported to 4.15 and 4.14 (at least)?

[akalenyu]

sure
/cherrypick release-v1.59

[kubevirt-bot]

@akalenyu: new pull request created: #3374

In response to this:

sure
/cherrypick release-v1.59

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

[akalenyu]

/cherrypick release-v1.58

[kubevirt-bot]

@akalenyu: new pull request created: #3375

In response to this:

/cherrypick release-v1.58

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

[akalenyu]

/cherrypick release-v1.57

[kubevirt-bot]

@akalenyu: new pull request created: #3376

In response to this:

/cherrypick release-v1.57

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.