Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

avocado 102+ has removed some log messages which are useful for our debugging #5721

Closed
dzhengfy opened this issue Jul 12, 2023 · 3 comments
Closed
Assignees
Labels

Comments

@dzhengfy
Copy link
Contributor

dzhengfy commented Jul 12, 2023

Hi avocado maintainers,

I ran one case by avocado command: avocado run --vt-type libvirt memory_snapshot.delete.paused.type_qcow2. Then I compare the log results from different avocado branches. See below:

Summary:

  • Line number is missing now
  • python module name in tp-libvirt is missing now
  • Long case names are displayed on every line although I only run 1 case by the avocado command

Questions:
For above summarized items, is it possible to support by a configuration or else? If possible, that will be very convenient for our debugging work like before.

Details as below:

92lts + nrunner + job.log:

2023-06-30 04:33:03,653 virsh            L0830 DEBUG| stdout: Domain 'avocado-vt-vm1' started
2023-06-30 04:33:03,653 virsh            L0831 DEBUG| stderr:
2023-06-30 04:33:03,653 virt_vm          L1203 DEBUG| Attempting to log into 'avocado-vt-vm1' (timeout 240s)
2023-06-30 04:33:05,524 env_process      L2136 DEBUG| avocado-vt-vm1 alive now. Used to failed to get register info from guest 1 times
2023-06-30 04:33:46,788 ip_sniffing      L0060 DEBUG| Updated HWADDR (52:54:00:63:74:b7)<->(192.168.122.168) IP pair into address cache
2023-06-30 04:33:47,285 virt_vm          L0928 DEBUG| Found/Verified IP 192.168.122.168 for VM avocado-vt-vm1 NIC 0
2023-06-30 04:33:48,976 **memory_snapshot_ L0077 DEBUG| Now vm xml after adding the disk:**
<domain xmlns:ns0="http://libosinfo.org/xmlns/libvirt/domain/1.0" type="kvm">

Good things are like:

  • From the shown line number for one log message, I can easily find the codes.
  • The message line is short and clean. This shows me good readability.

master + runner+ debug.log:

[stdlog] 2023-06-28 06:24:45,306 avocado.virttest.virsh DEBUG| stdout: Domain 'avocado-vt-vm1' started
[stdlog] 2023-06-28 06:24:45,306 avocado.virttest.virsh DEBUG| stderr:
[stdlog] 2023-06-28 06:24:45,306 avocado.virttest.virt_vm DEBUG| Attempting to log into 'avocado-vt-vm1' (timeout 240s)
[stdlog] 2023-06-28 06:24:48,727 avocado.virttest.env_process DEBUG| avocado-vt-vm1 alive now. Used to failed to get register info from guest 1 times
[stdlog] 2023-06-28 06:25:36,760 avocado.virttest.ip_sniffing DEBUG| Updated HWADDR (52:54:00:27:a4:f6)<->(192.168.122.95) IP pair into address cache
[stdlog] 2023-06-28 06:25:36,933 avocado.virttest.virt_vm DEBUG| Found/Verified IP 192.168.122.95 for VM avocado-vt-vm1 NIC 0
[stdlog] 2023-06-28 06:25:38,571 **avocado.test DEBUG| Now vm xml after adding the disk:**
[stdlog] <domain xmlns:ns0="http://libosinfo.org/xmlns/libvirt/domain/1.0" type="kvm">

Changes:

  • The line number is missing now.
  • The python module where the log message comes from is missing now, instead avocado.test is shown ( the codes are using test.log())

master + runner + full.log:

2023-06-28 06:24:45,397 avocado.virttest.virsh DEBUG| 1-type_specific.io-github-autotest-libvirt.memory_snapshot.delete.running.type_qcow2: stdout: Domain 'avocado-vt-vm1' started
2023-06-28 06:24:45,397 avocado.virttest.virsh DEBUG| 1-type_specific.io-github-autotest-libvirt.memory_snapshot.delete.running.type_qcow2: stderr:
2023-06-28 06:24:45,397 avocado.virttest.virt_vm DEBUG| 1-type_specific.io-github-autotest-libvirt.memory_snapshot.delete.running.type_qcow2: Attempting to log into 'avocado-vt-vm1' (timeout 240s)
2023-06-28 06:24:48,767 avocado.virttest.env_process DEBUG| 1-type_specific.io-github-autotest-libvirt.memory_snapshot.delete.running.type_qcow2: avocado-vt-vm1 alive now. Used to failed to get register info from guest 1 times
2023-06-28 06:25:36,811 avocado.virttest.ip_sniffing DEBUG| 1-type_specific.io-github-autotest-libvirt.memory_snapshot.delete.running.type_qcow2: Updated HWADDR (52:54:00:27:a4:f6)<->(192.168.122.95) IP pair into address cache
2023-06-28 06:25:36,964 avocado.virttest.virt_vm DEBUG| **1-type_specific.io-github-autotest-libvirt.memory_snapshot.delete.running.type_qcow2**: Found/Verified IP 192.168.122.95 for VM avocado-vt-vm1 NIC 0
2023-06-28 06:25:38,596 avocado.test DEBUG| 1-type_specific.io-github-autotest-libvirt.memory_snapshot.delete.running.type_qcow2: Now vm xml after adding the disk:
<domain xmlns:ns0="http://libosinfo.org/xmlns/libvirt/domain/1.0" type="kvm">

Additional changes:

  • Long case names are displayed in every line. I guess it might be required by parallel runners to differentiate multiple cases.
@richtja
Copy link
Contributor

richtja commented Jul 12, 2023

Hi avocado maintainers,

I ran one case by avocado command: avocado run --vt-type libvirt memory_snapshot.delete.paused.type_qcow2. Then I compare the log results from different avocado branches. See below:

Summary:

* Line number is missing now

* python module name in tp-libvirt is missing now

Hi @dzhengfy, thank you for your detailed description. I can confirm that these two are bugs and we will fix them for 103LTS version. We would like to keep the format from 92LTS as much as possible.

* Long case names are displayed on every line although I only run 1 case by the avocado command

Unfortunately, this is needed for parallel run of multiple tests to keep track of which log is part of which test. I understand that this doesn't make sense for one test, but we don't want to bring more complexity to the logging system to differentiate single and multiple tests.

Questions: For above summarized items, is it possible to support by a configuration or else? If possible, that will be very convenient for our debugging work like before.

We have an open issue #5469 about this topic and we plan to work on it, but unfortunately right now we are working on fixing bugs and stabilization before LTS version. Therefore, we don't plan to have it in the near future.

@richtja richtja added bug and removed enhancement labels Jul 12, 2023
@dzhengfy
Copy link
Contributor Author

@chunfuwen @chloerh @Yingshun

richtja added a commit to richtja/avocado that referenced this issue Jul 17, 2023
This commit addresses compatibility concerns by reverting the log
message format of Avocado instrumented tests back to the 92LTS
(Long-Term Support) version. By doing so, we ensure compatibility with
the upcoming LTS version.

Reference: avocado-framework#5721
Signed-off-by: Jan Richter <jarichte@redhat.com>
richtja added a commit to richtja/avocado that referenced this issue Jul 17, 2023
This commit addresses compatibility concerns by reverting the log
message format of Avocado instrumented tests back to the 92LTS
(Long-Term Support) version. By doing so, we ensure compatibility with
the upcoming LTS version.

Reference: avocado-framework#5721
Signed-off-by: Jan Richter <jarichte@redhat.com>
richtja added a commit to richtja/avocado that referenced this issue Jul 25, 2023
This commit addresses compatibility concerns by reverting the log
message format of Avocado instrumented tests back to the 92LTS
(Long-Term Support) version. By doing so, we ensure compatibility with
the upcoming LTS version.

Reference: avocado-framework#5721
Signed-off-by: Jan Richter <jarichte@redhat.com>
@richtja
Copy link
Contributor

richtja commented Aug 28, 2023

Resolved by #5732

@richtja richtja closed this as completed Aug 28, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
Archived in project
Development

No branches or pull requests

3 participants