Re: [KVM-AUTOTEST PATCH] A test patch - Boot VMs until one of them becomes unresponsive

[Yolkfull Chow <yzhou@redhat.com>]

On 06/11/2009 04:53 PM, Michael Goldish wrote:
> ----- "Yolkfull Chow"<yzhou@redhat.com>  wrote:
>
>    
>> Michael, these are the backtrace messages:
>>
>> ...
>> 20090611-064959
>> no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024:
>>
>> ERROR: run_once: Test failed: [Errno 12] Cannot allocate memory
>> 20090611-064959
>> no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024:
>>
>> DEBUG: run_once: Postprocessing on error...
>> 20090611-065000
>> no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024:
>>
>> DEBUG: postprocess_vm: Postprocessing VM 'vm1'...
>> 20090611-065000
>> no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024:
>>
>> DEBUG: postprocess_vm: VM object found in environment
>> 20090611-065000
>> no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024:
>>
>> DEBUG: send_monitor_cmd: Sending monitor command: screendump
>> /kvm-autotest/client/results/default/kvm_runtest_2.[RHEL-Server-5.3-64][None][1024][1][qcow2]<no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024>/debug/post_vm1.ppm
>> 20090611-065000
>> no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024:
>>
>> DEBUG: run_once: Contents of environment: {'vm__vm1':<kvm_vm.VM
>> instance at 0x92999a28>}
>> post-test sysinfo error:
>> Traceback (most recent call last):
>>     File "/kvm-autotest/client/common_lib/log.py", line 58, in
>> decorated_func
>>       fn(*args, **dargs)
>>     File "/kvm-autotest/client/bin/base_sysinfo.py", line 213, in
>> log_after_each_test
>>       log.run(test_sysinfodir)
>>     File "/kvm-autotest/client/bin/base_sysinfo.py", line 112, in run
>>       shell=True, env=env)
>>     File "/usr/lib64/python2.4/subprocess.py", line 412, in call
>>       return Popen(*args, **kwargs).wait()
>>     File "/usr/lib64/python2.4/subprocess.py", line 542, in __init__
>>       errread, errwrite)
>>     File "/usr/lib64/python2.4/subprocess.py", line 902, in
>> _execute_child
>>       self.pid = os.fork()
>> OSError: [Errno 12] Cannot allocate memory
>> 2009-06-11 06:50:02,859 Configuring logger for client level
>>           FAIL
>> kvm_runtest_2.[RHEL-Server-5.3-64][None][1024][1][qcow2]<no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024>
>>
>> kvm_runtest_2.[RHEL-Server-5.3-64][None][1024][1][qcow2]<no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024>
>>
>> timestamp=1244717402    localtime=Jun 11 06:50:02    Unhandled
>> OSError:
>> [Errno 12] Cannot allocate memory
>>             Traceback (most recent call last):
>>               File "/kvm-autotest/client/common_lib/test.py", line 304,
>>
>> in _exec
>>                 self.execute(*p_args, **p_dargs)
>>               File "/kvm-autotest/client/common_lib/test.py", line 187,
>>
>> in execute
>>                 self.run_once(*args, **dargs)
>>               File
>> "/kvm-autotest/client/tests/kvm_runtest_2/kvm_runtest_2.py", line 145,
>>
>> in run_once
>>                 routine_obj.routine(self, params, env)
>>               File
>> "/kvm-autotest/client/tests/kvm_runtest_2/kvm_tests.py", line 3071, in
>>
>> run_boot_vms
>>                 curr_vm_session = kvm_utils.wait_for(curr_vm.ssh_login,
>>
>> 240, 0, 2)
>>               File
>> "/kvm-autotest/client/tests/kvm_runtest_2/kvm_utils.py", line 797, in
>>
>> wait_for
>>                 output = func()
>>               File
>> "/kvm-autotest/client/tests/kvm_runtest_2/kvm_vm.py",
>> line 728, in ssh_login
>>                 session = kvm_utils.ssh(address, port, username,
>> password, prompt, timeout)
>>               File
>> "/kvm-autotest/client/tests/kvm_runtest_2/kvm_utils.py", line 553, in
>> ssh
>>                 return remote_login(command, password, prompt, "\n",
>> timeout)
>>               File
>> "/kvm-autotest/client/tests/kvm_runtest_2/kvm_utils.py", line 431, in
>>
>> remote_login
>>                 sub = kvm_spawn(command, linesep)
>>               File
>> "/kvm-autotest/client/tests/kvm_runtest_2/kvm_utils.py", line 114, in
>>
>> __init__
>>                 (pid, fd) = pty.fork()
>>               File "/usr/lib64/python2.4/pty.py", line 108, in fork
>>                 pid = os.fork()
>>             OSError: [Errno 12] Cannot allocate memory
>> Persistent state variable __group_level now set to 1
>>       END FAIL
>> kvm_runtest_2.[RHEL-Server-5.3-64][None][1024][1][qcow2]<no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024>
>>
>> kvm_runtest_2.[RHEL-Server-5.3-64][None][1024][1][qcow2]<no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024>
>>
>> timestamp=1244717403    localtime=Jun 11 06:50:03
>> Dropping caches
>> 2009-06-11 06:50:03,409 running: sync
>> JOB ERROR: Unhandled OSError: [Errno 12] Cannot allocate memory
>> Traceback (most recent call last):
>>     File "/kvm-autotest/client/bin/job.py", line 978, in step_engine
>>       execfile(self.control, global_control_vars, global_control_vars)
>>     File "/kvm-autotest/client/control", line 1030, in ?
>>       cfg_to_test("kvm_tests.cfg")
>>     File "/kvm-autotest/client/control", line 1013, in cfg_to_test
>>       current_status = job.run_test("kvm_runtest_2", params=dict,
>> tag=tagname)
>>     File "/kvm-autotest/client/bin/job.py", line 44, in wrapped
>>       utils.drop_caches()
>>     File "/kvm-autotest/client/bin/base_utils.py", line 638, in
>> drop_caches
>>       utils.system("sync")
>>     File "/kvm-autotest/client/common_lib/utils.py", line 510, in
>> system
>>       stdout_tee=sys.stdout, stderr_tee=sys.stderr).exit_status
>>     File "/kvm-autotest/client/common_lib/utils.py", line 330, in run
>>       bg_job = join_bg_jobs(
>>     File "/kvm-autotest/client/common_lib/utils.py", line 37, in
>> __init__
>>       stdin=stdin)
>>     File "/usr/lib64/python2.4/subprocess.py", line 542, in __init__
>>       errread, errwrite)
>>     File "/usr/lib64/python2.4/subprocess.py", line 902, in
>> _execute_child
>>       self.pid = os.fork()
>> OSError: [Errno 12] Cannot allocate memory
>>
>> Persistent state variable __group_level now set to 0
>> END ABORT    ----    ----    timestamp=1244717418    localtime=Jun 11
>>
>> 06:50:18    Unhandled OSError: [Errno 12] Cannot allocate memory
>>     Traceback (most recent call last):
>>       File "/kvm-autotest/client/bin/job.py", line 978, in step_engine
>>         execfile(self.control, global_control_vars,
>> global_control_vars)
>>       File "/kvm-autotest/client/control", line 1030, in ?
>>         cfg_to_test("kvm_tests.cfg")
>>       File "/kvm-autotest/client/control", line 1013, in cfg_to_test
>>         current_status = job.run_test("kvm_runtest_2", params=dict,
>> tag=tagname)
>>       File "/kvm-autotest/client/bin/job.py", line 44, in wrapped
>>         utils.drop_caches()
>>       File "/kvm-autotest/client/bin/base_utils.py", line 638, in
>> drop_caches
>>         utils.system("sync")
>>       File "/kvm-autotest/client/common_lib/utils.py", line 510, in
>> system
>>         stdout_tee=sys.stdout, stderr_tee=sys.stderr).exit_status
>>       File "/kvm-autotest/client/common_lib/utils.py", line 330, in
>> run
>>         bg_job = join_bg_jobs(
>>       File "/kvm-autotest/client/common_lib/utils.py", line 37, in
>> __init__
>>         stdin=stdin)
>>       File "/usr/lib64/python2.4/subprocess.py", line 542, in __init__
>>         errread, errwrite)
>>       File "/usr/lib64/python2.4/subprocess.py", line 902, in
>> _execute_child
>>         self.pid = os.fork()
>>     OSError: [Errno 12] Cannot allocate memory
>> [root@dhcp-66-70-9 kvm_runtest_2]#
>>      
> Thanks. It does indeed look like a legitimate OSError in os.fork().
>
> BTW, do you have any idea why the result dir has such a weird name?
> /kvm-autotest/client/results/default/kvm_runtest_2.[RHEL-Server-5.3-64][None][1024][1][qcow2]<no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024>/debug/post_vm1.ppm
>
> And why sometimes a normal looking tag appears (in the log messages):
> no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024
>
> Why all the [] and<>  in the weird version? Did you somehow do that intentionally, or is it some sort of bug?
> And why is 'None' there? The tag is supposed to be the test's 'shortname', which is determined by kvm_config.py
> as it parses kvm_tests.cfg (or the config file you're using).
>
> Normally the result dir should just be kvm_runtest_2.shortname, and in this case:
> kvm_runtest_2.no_boundary.local_stg.RHEL.5.3-server-64.no_ksm.boot_vms.e1000.user.size_1024
>    
Hi Michael, it's not any sort of defect or problem,  we just did that 
intentionally for some purpose. And now we had unified it with 
autotest's style. Thank you so much for kindly remind. :)

-- 
Yolkfull
Regards,