Am trying to run a test from libvirt (virsh_cpu_stats) and I see that when i set a pdb trace using pdb.set_trace() in the code, it enter the debugger but no output is shown fro the debugger.

But I guess it can step through or got to next instruction. PDB also responds to 'c' command and when 'c' command is given it goes through until it finds pdb.set_trace() again.

Here is the problem.

[root@phx3 virt]# ./run -t libvirt/
DEBUG LOG: /home/autotest/client/tests/virt/logs/run-2012-09-21-14.57.30/debug.log
TESTS: 20
libvirt.raw.virtio_blk.smp2.virtio_net.Fedora.17.64.virsh_cpu_stats.libvirton.expected_options.expected_option_none:n
s
s
p vm_name
s
s
n
c
FAIL (21.76 s)
libvirt.raw.virtio_blk.smp2.virtio_net.Fedora.17.64.virsh_cpu_stats.libvirton.expected_options.expected_option_start:c

As you can see above nothing is getting displayed. Same problem is when i use verbose output.

Did i miss something?

-prem

Test the virsh cpu-stats command

(1) Invoke virsh cpu-stats <domain> <options>
(2) Invoke virsh cpu-stats with following possible combination of options
         a. None      e. --start --count
         b. --start   f. --start --total
         c. --count   g. --count --total
         d. --total   h. --start --count --total
(3) Invoke virsh cpu-stats with a numeric argument
(4) Invoke virsh cpu-stats with an invalid string "xyz"
(5) Invoke virsh cpu-stats with above combinations with libvitrd service

stop

Pass Condition:

1. When option = 'total'
   a. Displayed Total cpu_time > User cpu_time > System cpu_time
   b. Displayed Total cpu_time >= User + System cpu_time
2. When option = 'start' or 'count'
   a. Displayed CPU's == Expected CPU's
   b. Cgroup cpu_time* >= sum of cpu_time of each cpu's displayed
3. When option has a combination of 'start', 'count', 'total'
   All the above conditions 1 & 2 are checked.
4. When option is None
   a. Displayed Total cpu_time >= sum of cpu_time of all cpu's displayed
   b. Pass condition when option = 'total' (1) is checked.

*Cgroup cpu_time is computed by reading domain specific cpuacct.usage_percpu
Delay in reading the percpu file will lead up to cgropu cpu_time being slightly
higher (in ns) than the displayed time.

This patchset tests virsh command domxml-from-native.

This patchset tests virsh command setmem.
virsh setmem can reset domain's memroy currently.

1. Prepare vm environment.
2. Prepare libvirt state.
3. Run test command and wait for current memory's stable.
4. Check result.
   TODO: support new libvirt with more options.

This patchset tests virsh command domxml-from-native.

Please see the documentation available here: https://github.com/autotest/autotest/wiki/DevelopmentWorkflow

To add an issue\to this tracking issue, simply update to the other issue with Adding to tracking issue #64". Note: There's no way to remove the tracking links, so if you're not sure, ask on the mailing list or IRC.

This test case assigns the different values for memory controller for a guest
and plans to check the following:

1. Whether the cgroup paramters are updated in the mounted path.
2. Check in guest if memory usage greater than the assigned one takes the necessary action.
3. Check whether the virsh memtune query gets updated properly.

Comments are welcome if anything missing.

When running tests with different spice options (copy-paste-disabled on vs off), tests running individually work fine.
However, when running these tests sequentially one after the other, an Unhandled TAP Creation Error is returned:

Unhandled TAPCreationError: Cannot Create TAP device... Device or Resource busy
[context: preprocessing creating 'vm1']

Formerly: autotest/autotest#548

Related code: https://github.com/autotest/virt-test/blob/master/kvm/tests/qemu_img.py

Open for anyone who wants to write it

Hi guys,

when developing a Windows test I got a lot of No DHCP lease for MAC 9a:2b:2c:2d:2e:2f or ...can't verify address... messages. Followed by can't connect to guest test failures.

The problem is 100% reproducible (on my laptop):

1. Execute any test on Windows XP
2. killall qemu-kvm, rm -f env, rm -f /tmp/address_poll*
3. Execute any test on Windows XP

There is a simple fix, login to the machine (vnc or nc with the old IP address) and run "ipconfig /renew". It returns error:
An error occurred while renewing interface Local Area Connection 5 : Access is denied. or
An error occurred while renewing interface Local Area Connection 5 : Unable to contact your DHCP server. Request has timed out.
but the IP address changes successfully and is recognized by autotest.

Funny was that by using GUI Control Panel -> Network Connections -> Local Area ... -> Support -> Repair didn't work, but cmd ipconfig /renew did.

My idea is that windows won't send dhcp request on boot when the old (previous run) address is still valid. But don't take me seriously, I don't understand Windows...

My laptop: Fedora 17, qemu-kvm-1.0.1-1.fc17.x86_64, current autotest git-next
Guest: Windows XP SP3

PS: I sometimes encounter broken bridge which requires to stop and start bridge (in virt-manager) and then everything works fine. This is not the case and bridge restart doesn't help.

Adding to tracking issue #497

1.Prepare test environment.

2.When the ibvirtd == "off", stop the libvirtd service

3.Run the autotest

4.Recover test environment.(If the libvirtd service is stopped ,start the libvirtd service.)

5.Confirm the test result

The autotest unit tests on the next branch fail if virsh is not available. As virsh is not a requirement for autotest, autotest.client.virt.virsh_unittest should either be skipped entirely or gracefully handle the case if virsh in not available without triggering a failure if the entire test suite is run.

This is a good idea proposed by @cevich:

ToDo: I've run into at least two situations where test modules could have used more control over pre/post process. Rather than unconditionally calling them, what about allowing test classes to override them. For example, the test module has already been imported at this point, why not do something like:

preprocess_func = getattr("preprocess_%s" % t_type, test_module, env_process.preprocess)
try:
    preprocesss_func(self, params, env)
finally:
    env.save()
...

Let's implement it after #533 is merged.

Comment will be updated soon

This patchset tests virsh command domxml-from-native.

main_vm = "rhel7-migration". This guest is currently in running state. When I have

vm = env.get_vm(params["main_vm"]), it returns a null object, even though the guest is listed and running.

Is Evn class broken? When I do vm.verify_alive() I get this error logged.

15:05:24 DEBUG| Running 'service libvirtd status'
15:05:24 INFO | Libvirtd service is running
15:05:25 INFO | VM Name = rhel7-migration
15:05:49 ERROR| FAIL -> AttributeError: 'NoneType' object has no attribute 'verify_alive'
1

As you can see above vm.verify_alive() fails with above message. As you can see one line above the message, i have these lines of code in my module.

vm_name = params.get("main_vm")
logging.info("main vm value = %s" % params["main_vm"])

So looks like get_vm is broken. Am unable to debug this due to issue #554

It was pointed out by Liu Sheng [email protected] that in several places we have architecture dependent code in the kvm/virt tests in general. He suggested to develop mechanisms to abstract arch specific code in an organized and centralized way. In his words:

And I find so many arch related codes are in so many files of kvm autotest and
autotest itself, most of them are in if-else style. As more and more arch will
support kvm, and some cases maybe arch related, it will be hard to manage the
arch related code. Can we have some infrastructure code to put them together and
give a uniform interface. Just like it is in linux kernel, the arch related code
are in arch dir, not in every .c file.

This issue tracks possible implementations for this future. Unfortunately nothing occurs to me in terms of implementation, so if someone has an idea, please manifest yourself :)

This is a good idea proposed by @cevich:

ToDo: I've run into at least two situations where test modules could have used more control over pre/post process. Rather than unconditionally calling them, what about allowing test classes to override them. For example, the test module has already been imported at this point, why not do something like:

preprocess_func = getattr("preprocess_%s" % t_type, test_module, env_process.preprocess)
try:
    preprocesss_func(self, params, env)
finally:
    env.save()
...

Let's implement it after #533 is merged.

For example

    # This works fine
    virsh.define(foobar, debug=True)
     
    # This works fine
    v = virsh.Virsh(debug=true)
    v.define(foobar)
     
    # This doesn't work
    v = virsh.Virsh()
    v.define(foobar) # debug is False (correct)
    v.debug = True
    v.define(foobar) # debug is False (incorrect)

(1) Call the virsh nodememstats command
(2) Get the output
(3) Check the against /proc/meminfo output
(4) Call the virsh nodememstats command with an unexpected option
(5) Call the virsh nodememstats command with libvirtd service stop

Hi,
In client mode netperf works fine but in server mode all tests in the topic don't finish the job, with no result (host status is Running until the job is aborted). Cleanup test case executes only one method host.cleanup(), so i tried to write my own test cases which execute cleanup and reboot methods. In both cases, tests don't finish and there were no results. When I tried execute something like host.run('echo sth') test case returned positive result. Attached below are logfiles from netperf and cleanup. Iperf and netpipe logfiles looks very similar to netperf log.

Cleanup logfile:

08/02 11:04:30 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/456-debug_user/test-client1
08/02 11:04:30 DEBUG| base_job:0349| Persistent state global_properties.tag now set to '456-debug_user/test-client1' 08/02 11:04:30 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:04:30 INFO |server_job:0534| Processing control file
08/02 11:04:30 DEBUG|base_utils:0077| Running '/usr/local/autotest/conmux/conmux-attach test-client1 echo 2> /dev/null' 08/02 11:04:30 DEBUG| ssh_host:0114| Running (ssh) 'ls /var/log/kern.log'
08/02 11:04:30 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_QzK1l0ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:30 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/autotmp_QzK1l0ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /var/log/kern.log
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /var/tmp'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /var/tmp/autoserv-XXXXXX'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /var/tmp/autoserv-qaenCD
08/02 11:04:31 INFO |logfile_mo:0052| Launching followfiles on target: test-client1, /var/tmp/autoserv-qaenCD, ['/var/log/kern.log']
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/bin/python[0-9]'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /usr/bin/python2
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /usr/bin/python2.7
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-M4ugJK
08/02 11:04:31 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:04:31 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:04:31 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_QzK1l0ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/server/hosts/monitors root@test-client1:"/tmp/autoserv-M4ugJK"'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:04:31 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:04:31 INFO |server_job:0117| START cleanup_test cleanup_test timestamp=1343905471 localtime=Aug 02 11:04:31
08/02 11:04:31 INFO | remote:0278| Reboot: initiating reboot 08/02 11:04:31 INFO |server_job:0117| START ---- reboot timestamp=1343905471 localtime=Aug 02 11:04:31
08/02 11:04:31 INFO |server_job:0117| GOOD ---- reboot.start timestamp=1343905471 localtime=Aug 02 11:04:31
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'sync; sync'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) '(( sync & sleep 5; reboot & sleep 60; reboot -f & sleep 10; reboot -nf & sleep 10; telinit 6 &) </dev/null >/dev/null 2>&1 &)'
08/02 11:04:31 DEBUG|abstract_s:0503| Host test-client1 pre-shutdown boot_id is e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:32 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:32 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:33 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:33 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:34 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:34 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:35 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:35 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:36 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:36 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:37 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:38 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:39 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:39 INFO |abstract_s:0606| Master ssh connection to test-client1 is down.
08/02 11:04:39 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_Ts6hJessh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:39 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_Ts6hJessh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:39 ERROR|base_utils:0114| [stderr] ssh: connect to host test-client1 port 22: Connection refused
08/02 11:04:39 DEBUG|abstract_s:0510| Host test-client1 is now unreachable over ssh, is down
08/02 11:04:39 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:04:39 INFO |abstract_s:0606| Master ssh connection to test-client1 is down.
08/02 11:04:39 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_KTb99Cssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:39 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_KTb99Cssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:39 ERROR|base_utils:0114| [stderr] ssh: connect to host test-client1 port 22: Connection refused
08/02 11:04:40 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:04:40 INFO |abstract_s:0606| Master ssh connection to test-client1 is down.
08/02 11:04:40 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_wyKVOyssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:40 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_wyKVOyssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:05:40 ERROR|base_utils:0114| [stderr] ssh: connect to host test-client1 port 22: Connection timed out
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:05:41 INFO |abstract_s:0606| Master ssh connection to test-client1 is down.
08/02 11:05:41 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_UBFbgEssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:05:41 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/autotmp_UBFbgEssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:05:41 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:05:41 INFO |server_job:0117| GOOD ---- reboot.verify timestamp=1343905541 localtime=Aug 02 11:05:41
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'ls /var/log/kern.log'
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] /var/log/kern.log
08/02 11:05:41 INFO |logfile_mo:0052| Launching followfiles on target: test-client1, /var/tmp/autoserv-qaenCD, ['/var/log/kern.log']
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/bin/python[0-9]'
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] /usr/bin/python2
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] /usr/bin/python2.7
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-7xiqGd
08/02 11:05:41 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:05:41 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:05:41 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_UBFbgEssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/server/hosts/monitors root@test-client1:"/tmp/autoserv-7xiqGd"'
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) '/bin/uname -r'
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] 3.2.0-23-generic-pae
08/02 11:05:41 INFO |server_job:0117| END GOOD ---- reboot kernel=3.2.0-23-generic-pae localtime=Aug 02 11:05:41 timestamp=1343905541
08/02 11:06:37 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/456-debug_user/test-client1
08/02 11:06:37 DEBUG| base_job:0349| Persistent state global_properties.tag now set to ''
08/02 11:06:37 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:06:37 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:06:37 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:06:37 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:06:37 ERROR|base_utils:0114| [stderr] Warning: Permanently added 'test-client1,192.168.254.11' (ECDSA) to the list of known hosts.
08/02 11:06:38 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:06:38 INFO |crashcolle:0021| Collecting crash information...
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:06:38 INFO |crashcolle:0052| test-client1 already up, collecting crash info
08/02 11:06:38 INFO |crashcolle:0099| Collecting /var/tmp/messages.autotest_start...
08/02 11:06:38 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:06:38 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:06:38 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/tmp/messages.autotest_start" /usr/local/autotest/results/456-debug_user/test-client1/crashinfo.test-client1/messages.at_start'
08/02 11:06:38 INFO |crashcolle:0099| Collecting /var/log/messages...
08/02 11:06:38 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:06:38 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:06:38 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/log/messages" /usr/local/autotest/results/456-debug_user/test-client1/crashinfo.test-client1/messages.raw'
08/02 11:06:38 INFO |crashcolle:0099| Collecting /var/log/monitor-ssh-reboots...
08/02 11:06:38 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:06:38 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:06:38 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/log/monitor-ssh-reboots" /usr/local/autotest/results/456-debug_user/test-client1/crashinfo.test-client1'
08/02 11:06:38 INFO |crashcolle:0119| Collecting 'dmesg' ...
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'dmesg'
08/02 11:06:58 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/456-debug_user/test-client1
08/02 11:06:58 DEBUG| base_job:0349| Persistent state global_properties.tag now set to ''
08/02 11:06:58 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:06:58 INFO |server_job:0534| Processing control file
08/02 11:06:58 INFO |server_job:0536| Finished processing control file

Netperf logfile:

08/02 11:08:25 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/457-debug_user/group0
08/02 11:08:25 DEBUG| base_job:0349| Persistent state global_properties.tag now set to '457-debug_user/group0'
08/02 11:08:25 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:08:25 INFO |server_job:0534| Processing control file
08/02 11:08:25 INFO |server_job:0117| START netperf2 netperf2 timestamp=1343905705 localtime=Aug 02 11:08:25
08/02 11:08:25 INFO | netperf2:0008| running on test-client1 and test-client2
08/02 11:08:25 INFO | netperf2:0008|
08/02 11:08:25 DEBUG|base_utils:0077| Running '/usr/local/autotest/conmux/conmux-attach test-client1 echo 2> /dev/null'
08/02 11:08:25 DEBUG| ssh_host:0114| Running (ssh) 'ls /var/log/kern.log'
08/02 11:08:25 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:08:25 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:08:25 DEBUG|base_utils:0114| [stderr] Warning: Permanently added 'test-client1,192.168.254.11' (ECDSA) to the list of known hosts.
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /var/log/kern.log
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /var/tmp'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /var/tmp/autoserv-XXXXXX'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /var/tmp/autoserv-TgXFIh
08/02 11:08:26 INFO |logfile_mo:0052| Launching followfiles on target: test-client1, /var/tmp/autoserv-TgXFIh, ['/var/log/kern.log']
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/bin/python[0-9]'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /usr/bin/python2
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /usr/bin/python2.7
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-57JcML
08/02 11:08:26 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:08:26 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:26 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/server/hosts/monitors root@test-client1:"/tmp/autoserv-57JcML"'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:08:26 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:08:26 DEBUG|base_utils:0077| Running '/usr/local/autotest/conmux/conmux-attach test-client2 echo 2> /dev/null'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'ls /var/log/kern.log'
08/02 11:08:26 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client2'
08/02 11:08:26 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client2'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /var/log/kern.log
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /var/tmp'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /var/tmp/autoserv-XXXXXX'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /var/tmp/autoserv-pk2k6t
08/02 11:08:26 INFO |logfile_mo:0052| Launching followfiles on target: test-client2, /var/tmp/autoserv-pk2k6t, ['/var/log/kern.log']
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/bin/python[0-9]'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /usr/bin/python2
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /usr/bin/python2.7
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-vugbtn
08/02 11:08:26 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:08:26 INFO |abstract_s:0117| XMARKWA make_rsync_cmd
08/02 11:08:26 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/server/hosts/monitors root@test-client2:"/tmp/autoserv-vugbtn"'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:08:26 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) '/sbin/iptables -L'
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain INPUT (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG|base_utils:0114| [stdout]
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain FORWARD (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG|base_utils:0114| [stdout]
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain OUTPUT (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables-save > /tmp/iptable-rules'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P INPUT ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P FORWARD ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P OUTPUT ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) '/sbin/iptables -L'
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain INPUT (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG|base_utils:0114| [stdout]
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain FORWARD (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG|base_utils:0114| [stdout]
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain OUTPUT (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables-save > /tmp/iptable-rules'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P INPUT ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P FORWARD ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P OUTPUT ACCEPT'
08/02 11:08:27 DEBUG|base_utils:0077| Running 'tools/make_clean'
08/02 11:08:27 DEBUG|base_utils:0077| Running 'tools/make_clean'
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] rm: cannot remove network_EthernetStressPlug/src': Permission denied 08/02 11:08:27 DEBUG|base_utils:0114| [stderr] rm: cannot removetmp/.testlock': Permission denied
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] rm: cannot remove network_EthernetStressPlug/src': Permission denied 08/02 11:08:27 DEBUG|base_utils:0114| [stderr] rm: cannot removetmp/.testlock': Permission denied
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning rmaptest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning disktest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning ipv6connect test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning signaltest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning rmaptest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning iosched_bugs test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning tracing_microbenchmark test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning disktest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning synctest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning ipv6connect test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning cyclictest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning signaltest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning rtc test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning iosched_bugs test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning aio_dio_bugs test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning tracing_microbenchmark test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning hackbench test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning synctest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning monotonic_time test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning cyclictest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning tsc test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning rtc test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning aio_dio_bugs test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning hackbench test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning monotonic_time test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning tsc test dir
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:08:27 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:08:27 INFO |autotest_r:0224| Installing autotest on test-client1
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'test -x /usr/local/autotest/autotest'
08/02 11:08:27 DEBUG|abstract_s:0458| Host test-client2 is now up
08/02 11:08:27 INFO |autotest_r:0224| Installing autotest on test-client2
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'test -x /usr/local/autotest/autotest'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'test -w /usr/local/autotest'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'test -w /usr/local/autotest'
08/02 11:08:27 DEBUG|autotest_r:0073| Found existing autodir at /usr/local/autotest
08/02 11:08:27 INFO |autotest_r:0229| Using installation dir /usr/local/autotest
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest'
08/02 11:08:27 DEBUG|autotest_r:0073| Found existing autodir at /usr/local/autotest
08/02 11:08:27 INFO |autotest_r:0229| Using installation dir /usr/local/autotest
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'rm -rf /usr/local/autotest/results/'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'rm -rf /usr/local/autotest/results/'
08/02 11:08:27 INFO |autotest_r:0249| Could not install autotest using the packaging system: No repos to install an autotest client from. Trying other methods
08/02 11:08:27 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:27 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:27 DEBUG|base_utils:0077| Running 'rsync -L --delete --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/client/tmp /usr/local/autotest/client/setup.py /usr/local/autotest/client/fsdev_disks.py /usr/local/autotest/client/job_unittest.py /usr/local/autotest/client/utils.pyc /usr/local/autotest/client/package.py /usr/local/autotest/client/harness_standalone.py /usr/local/autotest/client/local_host_unittest.py /usr/local/autotest/client/optparser.py /usr/local/autotest/client/os_dep.pyc /usr/local/autotest/client/kernel.pyc /usr/local/autotest/client/job.py /usr/local/autotest/client/common.pyc /usr/local/autotest/client/kernelexpand.py /usr/local/autotest/client/kernel.py /usr/local/autotest/client/setup_job.pyc /usr/local/autotest/client/autotest_local.py /usr/local/autotest/client/autotest_local.pyc /usr/local/autotest/client/fsinfo_unittest.py /usr/local/autotest/client/fsinfo.py /usr/local/autotest/client/base_utils.pyc /usr/local/autotest/client/local_host.py /usr/local/autotest/client/pyudev-0.15 /usr/local/autotest/client/client_logging_config.py /usr/local/autotest/client/job.pyc /usr/local/autotest/client/setup_modules.pyc /usr/local/autotest/client/os_dep.py /usr/local/autotest/client/kvm_control.py /usr/local/autotest/client/harness_autoserv.py /usr/local/autotest/client/setup_job_unittest.py /usr/local/autotest/client/cmdparser.py /usr/local/autotest/client/partition.py /usr/local/autotest/client/package_unittest.py /usr/local/autotest/client/autotestd_monitor /usr/local/autotest/client/base_utils.py /usr/local/autotest/client/partition.pyc /usr/local/autotest/client/harness_ABAT.py /usr/local/autotest/client/fsdev_mgr.py /usr/local/autotest/client/xen.pyc /usr/local/autotest/client/harness_unittest.py /usr/local/autotest/client/xen.py /usr/local/autotest/client/autotest_client /usr/local/autotest/client/results /usr/local/autotest/client/kernelexpand_unittest.py /usr/local/autotest/client/kernel_versions.py /usr/local/autotest/client/utils.py /usr/local/autotest/client/config.py /usr/local/autotest/client/kernel_versions_unittest.py /usr/local/autotest/client/client_logging_config.pyc /usr/local/autotest/client/base_sysinfo.pyc /usr/local/autotest/client/cmdparser.pyc /usr/local/autotest/client/test_config.py /usr/local/autotest/client/boottool.pyc /usr/local/autotest/client/partition_unittest.py /usr/local/autotest/client/local_host.pyc /usr/local/autotest/client/profiler.py /usr/local/autotest/client/net /usr/local/autotest/client/test.py /usr/local/autotest/client/parallel.pyc /usr/local/autotest/client/kernel_unittest.py /usr/local/autotest/client/harness.pyc /usr/local/autotest/client/LICENSE /usr/local/autotest/client/optparser.pyc /usr/local/autotest/client/TODO /usr/local/autotest/client/sysinfo.py /usr/local/autotest/client/harness_standalone.pyc /usr/local/autotest/client/harness_simple.py /usr/local/autotest/client/kernel_config.pyc /usr/local/autotest/client/setup_job.py /usr/local/autotest/client/virt /usr/local/autotest/client/fsdev_disks_unittest.py /usr/local/autotest/client/init.py /usr/local/autotest/client/common.py /usr/local/autotest/client/autotest /usr/local/autotest/client/harness.py /usr/local/autotest/client/cpuset.py /usr/local/autotest/client/tools /usr/local/autotest/client/init.pyc /usr/local/autotest/client/base_sysinfo.py /usr/local/autotest/client/autotestd /usr/local/autotest/client/setup_modules.py /usr/local/autotest/client/kernel_config.py /usr/local/autotest/client/package.pyc /usr/local/autotest/client/config /usr/local/autotest/client/test.pyc /usr/local/autotest/client/kernelexpand.pyc /usr/local/autotest/client/samples /usr/local/autotest/client/parallel.py /usr/local/autotest/client/autotest-local /usr/local/autotest/client/shared /usr/local/autotest/client/setup_modules_unittest.py /usr/local/autotest/client/sysinfo.pyc /usr/local/autotest/client/config.pyc /usr/local/autotest/client/deps/grubby/grubby-8.15.tar.bz2 root@test-client1:"/usr/local/autotest"'
08/02 11:08:27 INFO |autotest_r:0249| Could not install autotest using the packaging system: No repos to install an autotest client from. Trying other methods
08/02 11:08:27 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:27 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:27 DEBUG|base_utils:0077| Running 'rsync -L --delete --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/client/tmp /usr/local/autotest/client/setup.py /usr/local/autotest/client/fsdev_disks.py /usr/local/autotest/client/job_unittest.py /usr/local/autotest/client/utils.pyc /usr/local/autotest/client/package.py /usr/local/autotest/client/harness_standalone.py /usr/local/autotest/client/local_host_unittest.py /usr/local/autotest/client/optparser.py /usr/local/autotest/client/os_dep.pyc /usr/local/autotest/client/kernel.pyc /usr/local/autotest/client/job.py /usr/local/autotest/client/common.pyc /usr/local/autotest/client/kernelexpand.py /usr/local/autotest/client/kernel.py /usr/local/autotest/client/setup_job.pyc /usr/local/autotest/client/autotest_local.py /usr/local/autotest/client/autotest_local.pyc /usr/local/autotest/client/fsinfo_unittest.py /usr/local/autotest/client/fsinfo.py /usr/local/autotest/client/base_utils.pyc /usr/local/autotest/client/local_host.py /usr/local/autotest/client/pyudev-0.15 /usr/local/autotest/client/client_logging_config.py /usr/local/autotest/client/job.pyc /usr/local/autotest/client/setup_modules.pyc /usr/local/autotest/client/os_dep.py /usr/local/autotest/client/kvm_control.py /usr/local/autotest/client/harness_autoserv.py /usr/local/autotest/client/setup_job_unittest.py /usr/local/autotest/client/cmdparser.py /usr/local/autotest/client/partition.py /usr/local/autotest/client/package_unittest.py /usr/local/autotest/client/autotestd_monitor /usr/local/autotest/client/base_utils.py /usr/local/autotest/client/partition.pyc /usr/local/autotest/client/harness_ABAT.py /usr/local/autotest/client/fsdev_mgr.py /usr/local/autotest/client/xen.pyc /usr/local/autotest/client/harness_unittest.py /usr/local/autotest/client/xen.py /usr/local/autotest/client/autotest_client /usr/local/autotest/client/results /usr/local/autotest/client/kernelexpand_unittest.py /usr/local/autotest/client/kernel_versions.py /usr/local/autotest/client/utils.py /usr/local/autotest/client/config.py /usr/local/autotest/client/kernel_versions_unittest.py /usr/local/autotest/client/client_logging_config.pyc /usr/local/autotest/client/base_sysinfo.pyc /usr/local/autotest/client/cmdparser.pyc /usr/local/autotest/client/test_config.py /usr/local/autotest/client/boottool.pyc /usr/local/autotest/client/partition_unittest.py /usr/local/autotest/client/local_host.pyc /usr/local/autotest/client/profiler.py /usr/local/autotest/client/net /usr/local/autotest/client/test.py /usr/local/autotest/client/parallel.pyc /usr/local/autotest/client/kernel_unittest.py /usr/local/autotest/client/harness.pyc /usr/local/autotest/client/LICENSE /usr/local/autotest/client/optparser.pyc /usr/local/autotest/client/TODO /usr/local/autotest/client/sysinfo.py /usr/local/autotest/client/harness_standalone.pyc /usr/local/autotest/client/harness_simple.py /usr/local/autotest/client/kernel_config.pyc /usr/local/autotest/client/setup_job.py /usr/local/autotest/client/virt /usr/local/autotest/client/fsdev_disks_unittest.py /usr/local/autotest/client/init.py /usr/local/autotest/client/common.py /usr/local/autotest/client/autotest /usr/local/autotest/client/harness.py /usr/local/autotest/client/cpuset.py /usr/local/autotest/client/tools /usr/local/autotest/client/init.pyc /usr/local/autotest/client/base_sysinfo.py /usr/local/autotest/client/autotestd /usr/local/autotest/client/setup_modules.py /usr/local/autotest/client/kernel_config.py /usr/local/autotest/client/package.pyc /usr/local/autotest/client/config /usr/local/autotest/client/test.pyc /usr/local/autotest/client/kernelexpand.pyc /usr/local/autotest/client/samples /usr/local/autotest/client/parallel.py /usr/local/autotest/client/autotest-local /usr/local/autotest/client/shared /usr/local/autotest/client/setup_modules_unittest.py /usr/local/autotest/client/sysinfo.pyc /usr/local/autotest/client/config.pyc /usr/local/autotest/client/deps/grubby/grubby-8.15.tar.bz2 root@test-client2:"/usr/local/autotest"'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest/profilers'
08/02 11:08:27 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:27 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:27 DEBUG|base_utils:0077| Running 'rsync -L --delete --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/client/profilers/init.py root@test-client1:"/usr/local/autotest/profilers"'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p '/usr/local/autotest/site_tests';touch '/usr/local/autotest/site_tests'/init.py;mkdir -p '/usr/local/autotest/tests';touch '/usr/local/autotest/tests'/init.py;mkdir -p '/usr/local/autotest/deps';touch '/usr/local/autotest/deps'/init.py'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest/tmp'
08/02 11:08:27 INFO |autotest_r:0262| Installation of autotest completed
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:08:27 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:08:27 DEBUG|autotest_r:0065| Using existing host autodir: /usr/local/autotest
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/local/autotest/autotest > /dev/null 2>&1'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tmp'
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tmp: not mounted
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tests/download'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest/profilers'
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tests/download: not mounted
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/local/autotest/autotest > /dev/null 2>&1'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tmp'
08/02 11:08:27 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:27 INFO |abstract_s:0117| XMARKWA make_rsync_cmd
08/02 11:08:27 DEBUG|base_utils:0077| Running 'rsync -L --delete --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/client/profilers/init.py root@test-client2:"/usr/local/autotest/profilers"'
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tmp: not mounted
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tests/download'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tests/download: not mounted
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /usr/local/autotest/control.autoserv;rm -f /usr/local/autotest/tmp/control.autoserv.state;rm -f /usr/local/autotest/control;rm -f /usr/local/autotest/tmp/control.state'
08/02 11:08:28 DEBUG| base_job:0349| Persistent state client.sysinfo now set to {'test': set([sysinfo.command('dmesg -c', 'dmesg', False), sysinfo.command('df -mP', 'df', False)]), 'boot': set([sysinfo.command('gcc --version', 'gcc--version', False), sysinfo.command('ld --version', 'ld--version', False), sysinfo.logfile('/proc/partitions', 'partitions', False), sysinfo.logfile('/proc/interrupts', 'interrupts', False), sysinfo.command('hostname', 'hostname', False), sysinfo.command('mount', 'mount', False), sysinfo.logfile('/proc/cmdline', 'cmdline', True), sysinfo.logfile('/proc/version', 'version', False), sysinfo.command('lspci -vvn', 'lspci-vvn', False), sysinfo.logfile('/proc/slabinfo', 'slabinfo', False), sysinfo.logfile('/proc/modules', 'modules', False), sysinfo.logfile('/proc/mounts', 'proc_mounts', False), sysinfo.logfile('/proc/cpuinfo', 'cpuinfo', False), sysinfo.command('uptime', 'uptime', False), sysinfo.logfile('/proc/pci', 'pci', False), sysinfo.logfile('/proc/meminfo', 'meminfo', False), sysinfo.command('uname -a', 'uname', True)])}
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/tmpsjKk2S root@test-client1:"/usr/local/autotest/tmp/control.autoserv.init.state"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p '/usr/local/autotest/site_tests';touch '/usr/local/autotest/site_tests'/init.py;mkdir -p '/usr/local/autotest/tests';touch '/usr/local/autotest/tests'/init.py;mkdir -p '/usr/local/autotest/deps';touch '/usr/local/autotest/deps'/init.py'
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /tmp/autoserv-PD15m7/tmpagBt6q root@test-client1:"/usr/local/autotest/control.autoserv"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest/tmp'
08/02 11:08:28 INFO |autotest_r:0262| Installation of autotest completed
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:08:28 DEBUG|abstract_s:0458| Host test-client2 is now up
08/02 11:08:28 DEBUG|autotest_r:0065| Using existing host autodir: /usr/local/autotest
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/local/autotest/autotest > /dev/null 2>&1'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tmp'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:08:28 DEBUG|base_utils:0114| [stdout] 07f6f514-affe-4104-a182-6c81f91e20b6
08/02 11:08:28 INFO |autotest_r:0707| Executing /usr/local/autotest/autotest /usr/local/autotest/control phase 0
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tmp: not mounted
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tests/download'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tests/download: not found
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/local/autotest/autotest > /dev/null 2>&1'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tmp'
08/02 11:08:28 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-kb9Rhe
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/tmpC_WFZN root@test-client1:"/usr/local/autotest/global_config.ini"'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tmp: not mounted
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tests/download'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tests/download: not found
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /usr/local/autotest/control.autoserv;rm -f /usr/local/autotest/tmp/control.autoserv.state;rm -f /usr/local/autotest/control;rm -f /usr/local/autotest/tmp/control.state'
08/02 11:08:28 DEBUG| base_job:0349| Persistent state client.sysinfo now set to {'test': set([sysinfo.command('dmesg -c', 'dmesg', False), sysinfo.command('df -mP', 'df', False)]), 'boot': set([sysinfo.command('gcc --version', 'gcc--version', False), sysinfo.command('ld --version', 'ld--version', False), sysinfo.logfile('/proc/partitions', 'partitions', False), sysinfo.logfile('/proc/interrupts', 'interrupts', False), sysinfo.command('hostname', 'hostname', False), sysinfo.command('mount', 'mount', False), sysinfo.logfile('/proc/cmdline', 'cmdline', True), sysinfo.logfile('/proc/version', 'version', False), sysinfo.command('lspci -vvn', 'lspci-vvn', False), sysinfo.logfile('/proc/slabinfo', 'slabinfo', False), sysinfo.logfile('/proc/modules', 'modules', False), sysinfo.logfile('/proc/mounts', 'proc_mounts', False), sysinfo.logfile('/proc/cpuinfo', 'cpuinfo', False), sysinfo.command('uptime', 'uptime', False), sysinfo.logfile('/proc/pci', 'pci', False), sysinfo.logfile('/proc/meminfo', 'meminfo', False), sysinfo.command('uname -a', 'uname', True)])}
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/tmpXLkxvl root@test-client2:"/usr/local/autotest/tmp/control.autoserv.init.state"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'nohup /usr/local/autotest/autotestd /tmp/autoserv-kb9Rhe -H autoserv --verbose --hostname=test-client1 --user=debug_user /usr/local/autotest/control.autoserv >/dev/null 2>/dev/null &'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) '/usr/local/autotest/autotestd_monitor /tmp/autoserv-kb9Rhe 0 0'
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /tmp/autoserv-SJhcnl/tmpg_mx8s root@test-client2:"/usr/local/autotest/control.autoserv"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:08:28 DEBUG|base_utils:0114| [stdout] ab083a36-5d60-485b-b808-8d21d54473a5
08/02 11:08:28 INFO |autotest_r:0707| Executing /usr/local/autotest/autotest /usr/local/autotest/control phase 0
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:08:28 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-atrOMr
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/tmp5twp7J root@test-client2:"/usr/local/autotest/global_config.ini"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'nohup /usr/local/autotest/autotestd /tmp/autoserv-atrOMr -H autoserv --verbose --hostname=test-client2 --user=debug_user /usr/local/autotest/control.autoserv >/dev/null 2>/dev/null &'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) '/usr/local/autotest/autotestd_monitor /tmp/autoserv-atrOMr 0 0'
08/02 11:08:29 INFO |server_job:0117| START ---- ---- timestamp=1343905709 localtime=Aug 02 11:08:29
08/02 11:08:29 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_12n74Wharness-fifo/autoserv.fifo'
08/02 11:08:29 INFO |server_job:0117| START netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905709 localtime=Aug 02 11:08:29
08/02 11:08:29 INFO |server_job:0117| START ---- ---- timestamp=1343905709 localtime=Aug 02 11:08:29
08/02 11:08:29 INFO |autotest_r:1030| Bundling /usr/local/autotest/client/tests/netperf2 into test-netperf2.tar.bz2
08/02 11:08:29 DEBUG|base_utils:0077| Running 'tar -cf /usr/local/autotest/tmp/tmp/_autotmp_ZuY462autoserv-packager/test-netperf2.tar.bz2.tmp -C /usr/local/autotest/client/tests/netperf2 -j .'
08/02 11:08:29 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_I53cMEharness-fifo/autoserv.fifo'
08/02 11:08:29 INFO |server_job:0117| START netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905709 localtime=Aug 02 11:08:29
08/02 11:08:29 INFO |autotest_r:1030| Bundling /usr/local/autotest/client/tests/netperf2 into test-netperf2.tar.bz2
08/02 11:08:29 DEBUG|base_utils:0077| Running 'tar -cf /usr/local/autotest/tmp/tmp/_autotmp_Q1PuQ_autoserv-packager/test-netperf2.tar.bz2.tmp -C /usr/local/autotest/client/tests/netperf2 -j .'
08/02 11:08:30 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:30 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:30 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/_autotmp_ZuY462autoserv-packager/test-netperf2.tar.bz2 root@test-client1:"/usr/local/autotest/tmp/packages/test-netperf2.tar.bz2"'
08/02 11:08:30 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:30 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:30 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/_autotmp_Q1PuQ_autoserv-packager/test-netperf2.tar.bz2 root@test-client2:"/usr/local/autotest/tmp/packages/test-netperf2.tar.bz2"'
08/02 11:08:30 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_xFyDQnharness-fifo/autoserv.fifo'
08/02 11:08:30 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_Fsz9Urharness-fifo/autoserv.fifo'
08/02 11:08:31 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_OUjZZQharness-fifo/autoserv.fifo'
08/02 11:08:31 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_vh0e9Pharness-fifo/autoserv.fifo'
08/02 11:09:15 INFO |server_job:0117| GOOD netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905755 localtime=Aug 02 11:09:15 completed successfully
08/02 11:09:15 INFO |server_job:0117| GOOD netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905754 localtime=Aug 02 11:09:14 completed successfully
08/02 11:09:15 INFO |server_job:0117| END GOOD netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905755 localtime=Aug 02 11:09:15
08/02 11:09:15 INFO |server_job:0117| END GOOD netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905754 localtime=Aug 02 11:09:14
08/02 11:09:15 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:09:15 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:09:15 DEBUG|abstract_s:0458| Host test-client2 is now up
08/02 11:09:15 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:09:15 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:09:15 DEBUG|base_utils:0077| Running 'rsync --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/usr/local/autotest/results/default/" /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2'
08/02 11:09:15 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:09:15 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:09:15 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:09:15 DEBUG|base_utils:0077| Running 'rsync --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/usr/local/autotest/results/default/" /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1'
08/02 11:09:15 DEBUG| ssh_host:0114| Running (ssh) 'echo A > /usr/local/autotest/tmp/tmp/_autotmp_ZpyZREharness-fifo/autoserv.fifo'
08/02 11:09:15 DEBUG| ssh_host:0114| Running (ssh) 'echo A > /usr/local/autotest/tmp/tmp/_autotmp_hkbDeeharness-fifo/autoserv.fifo'
08/02 11:09:15 INFO |server_job:0117| END GOOD ---- ---- timestamp=1343905755 localtime=Aug 02 11:09:15
08/02 11:09:15 INFO |server_job:0117| END GOOD ---- ---- timestamp=1343905755 localtime=Aug 02 11:09:15
08/02 11:09:17 INFO |autotest_r:0792| Client complete
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:09:17 INFO |autotest_r:0792| Client complete
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:09:17 DEBUG|abstract_s:0458| Host test-client2 is now up
08/02 11:09:17 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:09:17 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:09:17 DEBUG|base_utils:0077| Running 'rsync --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/usr/local/autotest/results/default/" /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2'
08/02 11:09:17 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:09:17 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:09:17 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:09:17 DEBUG|base_utils:0077| Running 'rsync --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/usr/local/autotest/results/default/" /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1'
08/02 11:09:17 DEBUG| base_job:0242| Value of client.sysinfo is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0245| Importing client.harness from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0245| Importing client.steps from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0245| Importing client._record_indent from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0242| Value of global_properties.tag is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0242| Value of global_properties.last_boot_tag is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0391| Persistent state client.* deleted
08/02 11:09:17 DEBUG| base_job:0242| Value of client.sysinfo is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0245| Importing client.harness from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0245| Importing client.steps from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0245| Importing client._record_indent from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0242| Value of global_properties.tag is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0242| Value of global_properties.last_boot_tag is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0391| Persistent state client.* deleted
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) '/sbin/iptables -L'
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain INPUT (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG|base_utils:0114| [stdout]
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain FORWARD (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG|base_utils:0114| [stdout]
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain OUTPUT (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'ls "/tmp/iptable-rules" > /dev/null'
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'iptables-restore < /tmp/iptable-rules'
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) '/sbin/iptables -L'
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain INPUT (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG|base_utils:0114| [stdout]
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain FORWARD (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG|base_utils:0114| [stdout]
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain OUTPUT (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'ls "/tmp/iptable-rules" > /dev/null'
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'iptables-restore < /tmp/iptable-rules'
08/02 11:21:57 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/457-debug_user/group0
08/02 11:21:57 DEBUG| base_job:0349| Persistent state global_properties.tag now set to ''
08/02 11:21:57 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:21:57 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_RI7quYssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpX63eQ6 -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:21:57 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_RI7quYssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpX63eQ6 -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:21:57 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client2'
08/02 11:21:57 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client2'
08/02 11:21:57 ERROR|base_utils:0114| [stderr] Warning: Permanently added 'test-client2,192.168.254.12' (ECDSA) to the list of known hosts.
08/02 11:21:57 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:21:57 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:21:57 INFO |crashcolle:0021| Collecting crash information...
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:21:57 INFO |crashcolle:0052| test-client2 already up, collecting crash info
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/tmp/messages.autotest_start...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:21:57 INFO |crashcolle:0021| Collecting crash information...
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/var/tmp/messages.autotest_start" /usr/local/autotest/results/457-debug_user/group0/crashinfo.test-client2/messages.at_start'
08/02 11:21:57 INFO |crashcolle:0052| test-client1 already up, collecting crash info
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/tmp/messages.autotest_start...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_RI7quYssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpX63eQ6 -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/tmp/messages.autotest_start" /usr/local/autotest/results/457-debug_user/group0/crashinfo.test-client1/messages.at_start'
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/log/messages...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/var/log/messages" /usr/local/autotest/results/457-debug_user/group0/crashinfo.test-client2/messages.raw'
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/log/messages...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_RI7quYssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpX63eQ6 -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/log/messages" /usr/local/autotest/results/457-debug_user/group0/crashinfo.test-client1/messages.raw'
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/log/monitor-ssh-reboots...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/var/log/monitor-ssh-reboots" /usr/local/autotest/results/457-debug_user/group0/crashinfo

When running tests with different spice options (copy-paste-disabled on vs off), tests running individually work fine.
However, when running these tests sequentially one after the other, an Unhandled TAP Creation Error is returned:

Unhandled TAPCreationError: Cannot Create TAP device... Device or Resource busy
[context: preprocessing creating 'vm1']

Formerly: autotest/autotest#547

Example code:

• https://github.com/autotest/virt-test/blob/master/tests/netperf.py
• https://github.com/autotest/virt-test/blob/master/tests/ntttcp.py

Am trying to run a test from libvirt (virsh_cpu_stats) and I see that when i set a pdb trace using pdb.set_trace() in the code, it enter the debugger but no output is shown fro the debugger.

But I guess it can step through or got to next instruction. PDB also responds to 'c' command and when 'c' command is given it goes through until it finds pdb.set_trace() again.

Here is the problem.

[root@phx3 virt]# ./run -t libvirt/
DEBUG LOG: /home/autotest/client/tests/virt/logs/run-2012-09-21-14.57.30/debug.log
TESTS: 20
libvirt.raw.virtio_blk.smp2.virtio_net.Fedora.17.64.virsh_cpu_stats.libvirton.expected_options.expected_option_none:n
s
s
p vm_name
s
s
n
c
FAIL (21.76 s)
libvirt.raw.virtio_blk.smp2.virtio_net.Fedora.17.64.virsh_cpu_stats.libvirton.expected_options.expected_option_start:c

As you can see above nothing is getting displayed. Same problem is when i use verbose output.

Did i miss something?

-prem

Comments will be added soon.

Adding to tracking issue #497

1.Prepare test environment.

2.When the ibvirtd == "off", stop the libvirtd service

3.Run the autotest

4.Recover test environment.(If the libvirtd service is stopped ,start the libvirtd service.)

5.Confirm the test result

The autotest unit tests on the next branch fail if virsh is not available. As virsh is not a requirement for autotest, autotest.client.virt.virsh_unittest should either be skipped entirely or gracefully handle the case if virsh in not available without triggering a failure if the entire test suite is run.

main_vm = "rhel7-migration". This guest is currently in running state. When I have

vm = env.get_vm(params["main_vm"]), it returns a null object, even though the guest is listed and running.

Is Evn class broken? When I do vm.verify_alive() I get this error logged.

15:05:24 DEBUG| Running 'service libvirtd status'
15:05:24 INFO | Libvirtd service is running
15:05:25 INFO | VM Name = rhel7-migration
15:05:49 ERROR| FAIL -> AttributeError: 'NoneType' object has no attribute 'verify_alive'
1

As you can see above vm.verify_alive() fails with above message. As you can see one line above the message, i have these lines of code in my module.

vm_name = params.get("main_vm")
logging.info("main vm value = %s" % params["main_vm"])

So looks like get_vm is broken. Am unable to debug this due to issue #554

I find there is no way to add profilers when creating a job using cli/atest.

So I changed the cli/job.py to add in the profiler related options.

diff job.py job_new.py

385a386,392

    self.parser.add_option('-r', '--profiler',
                           help='List of profiler to run')

    self.parser.add_option('--profile_only',
                           help='Whether or not run each test without profilers first',
                           default=False, action='store_true')

485a493,500
if options.profiler:
profilers = [t.strip() for t in options.profiler.split(',') if t.strip()]
self.ctrl_file_data['profilers'] = profilers

    if options.profile_only:
        self.ctrl_file_data['profile_only'] = True
    else:
        self.ctrl_file_data['profile_only'] = False

And now the cli/atest works well with profilers.

1.Prepare test environment.

2.When the libvirtd == "off", stop the libvirtd service

3.Run the autotest

4.Recover test environment.(If the libvirtd service is stopped ,start the libvirtd service.)

5.Confirm the test result

Comments will be added soon.

This patchset tests virsh command setmem.
virsh setmem can reset domain's memroy currently.

1. Prepare vm environment.
2. Prepare libvirt state.
3. Run test command and wait for current memory's stable.
4. Check result.
   TODO: support new libvirt with more options.

Hi,
In client mode netperf works fine but in server mode all tests in the topic don't finish the job, with no result (host status is Running until the job is aborted). Cleanup test case executes only one method host.cleanup(), so i tried to write my own test cases which execute cleanup and reboot methods. In both cases, tests don't finish and there were no results. When I tried execute something like host.run('echo sth') test case returned positive result. Attached below are logfiles from netperf and cleanup. Iperf and netpipe logfiles looks very similar to netperf log.

Cleanup logfile:

08/02 11:04:30 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/456-debug_user/test-client1
08/02 11:04:30 DEBUG| base_job:0349| Persistent state global_properties.tag now set to '456-debug_user/test-client1' 08/02 11:04:30 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:04:30 INFO |server_job:0534| Processing control file
08/02 11:04:30 DEBUG|base_utils:0077| Running '/usr/local/autotest/conmux/conmux-attach test-client1 echo 2> /dev/null' 08/02 11:04:30 DEBUG| ssh_host:0114| Running (ssh) 'ls /var/log/kern.log'
08/02 11:04:30 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_QzK1l0ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:30 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/autotmp_QzK1l0ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /var/log/kern.log
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /var/tmp'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /var/tmp/autoserv-XXXXXX'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /var/tmp/autoserv-qaenCD
08/02 11:04:31 INFO |logfile_mo:0052| Launching followfiles on target: test-client1, /var/tmp/autoserv-qaenCD, ['/var/log/kern.log']
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/bin/python[0-9]'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /usr/bin/python2
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /usr/bin/python2.7
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-M4ugJK
08/02 11:04:31 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:04:31 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:04:31 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_QzK1l0ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/server/hosts/monitors root@test-client1:"/tmp/autoserv-M4ugJK"'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:04:31 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:04:31 INFO |server_job:0117| START cleanup_test cleanup_test timestamp=1343905471 localtime=Aug 02 11:04:31
08/02 11:04:31 INFO | remote:0278| Reboot: initiating reboot 08/02 11:04:31 INFO |server_job:0117| START ---- reboot timestamp=1343905471 localtime=Aug 02 11:04:31
08/02 11:04:31 INFO |server_job:0117| GOOD ---- reboot.start timestamp=1343905471 localtime=Aug 02 11:04:31
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'sync; sync'
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) '(( sync & sleep 5; reboot & sleep 60; reboot -f & sleep 10; reboot -nf & sleep 10; telinit 6 &) </dev/null >/dev/null 2>&1 &)'
08/02 11:04:31 DEBUG|abstract_s:0503| Host test-client1 pre-shutdown boot_id is e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:31 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:31 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:32 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:32 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:33 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:33 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:34 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:34 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:35 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:35 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:36 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:36 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:37 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:38 DEBUG|base_utils:0114| [stdout] e2aecfb1-dbb3-4e7e-823b-a7d16a81a8c7
08/02 11:04:39 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:04:39 INFO |abstract_s:0606| Master ssh connection to test-client1 is down.
08/02 11:04:39 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_Ts6hJessh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:39 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_Ts6hJessh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:39 ERROR|base_utils:0114| [stderr] ssh: connect to host test-client1 port 22: Connection refused
08/02 11:04:39 DEBUG|abstract_s:0510| Host test-client1 is now unreachable over ssh, is down
08/02 11:04:39 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:04:39 INFO |abstract_s:0606| Master ssh connection to test-client1 is down.
08/02 11:04:39 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_KTb99Cssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:39 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_KTb99Cssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:39 ERROR|base_utils:0114| [stderr] ssh: connect to host test-client1 port 22: Connection refused
08/02 11:04:40 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:04:40 INFO |abstract_s:0606| Master ssh connection to test-client1 is down.
08/02 11:04:40 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_wyKVOyssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:04:40 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_wyKVOyssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:05:40 ERROR|base_utils:0114| [stderr] ssh: connect to host test-client1 port 22: Connection timed out
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:05:41 INFO |abstract_s:0606| Master ssh connection to test-client1 is down.
08/02 11:05:41 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_UBFbgEssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:05:41 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/autotmp_UBFbgEssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:05:41 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:05:41 INFO |server_job:0117| GOOD ---- reboot.verify timestamp=1343905541 localtime=Aug 02 11:05:41
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'ls /var/log/kern.log'
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] /var/log/kern.log
08/02 11:05:41 INFO |logfile_mo:0052| Launching followfiles on target: test-client1, /var/tmp/autoserv-qaenCD, ['/var/log/kern.log']
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/bin/python[0-9]'
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] /usr/bin/python2
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] /usr/bin/python2.7
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-7xiqGd
08/02 11:05:41 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:05:41 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:05:41 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_UBFbgEssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpuAL3Mf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/server/hosts/monitors root@test-client1:"/tmp/autoserv-7xiqGd"'
08/02 11:05:41 DEBUG| ssh_host:0114| Running (ssh) '/bin/uname -r'
08/02 11:05:41 DEBUG|base_utils:0114| [stdout] 3.2.0-23-generic-pae
08/02 11:05:41 INFO |server_job:0117| END GOOD ---- reboot kernel=3.2.0-23-generic-pae localtime=Aug 02 11:05:41 timestamp=1343905541
08/02 11:06:37 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/456-debug_user/test-client1
08/02 11:06:37 DEBUG| base_job:0349| Persistent state global_properties.tag now set to ''
08/02 11:06:37 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:06:37 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:06:37 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:06:37 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:06:37 ERROR|base_utils:0114| [stderr] Warning: Permanently added 'test-client1,192.168.254.11' (ECDSA) to the list of known hosts.
08/02 11:06:38 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:06:38 INFO |crashcolle:0021| Collecting crash information...
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:06:38 INFO |crashcolle:0052| test-client1 already up, collecting crash info
08/02 11:06:38 INFO |crashcolle:0099| Collecting /var/tmp/messages.autotest_start...
08/02 11:06:38 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:06:38 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:06:38 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/tmp/messages.autotest_start" /usr/local/autotest/results/456-debug_user/test-client1/crashinfo.test-client1/messages.at_start'
08/02 11:06:38 INFO |crashcolle:0099| Collecting /var/log/messages...
08/02 11:06:38 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:06:38 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:06:38 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/log/messages" /usr/local/autotest/results/456-debug_user/test-client1/crashinfo.test-client1/messages.raw'
08/02 11:06:38 INFO |crashcolle:0099| Collecting /var/log/monitor-ssh-reboots...
08/02 11:06:38 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:06:38 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:06:38 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_viYsOcssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpsAqvgT -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/log/monitor-ssh-reboots" /usr/local/autotest/results/456-debug_user/test-client1/crashinfo.test-client1'
08/02 11:06:38 INFO |crashcolle:0119| Collecting 'dmesg' ...
08/02 11:06:38 DEBUG| ssh_host:0114| Running (ssh) 'dmesg'
08/02 11:06:58 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/456-debug_user/test-client1
08/02 11:06:58 DEBUG| base_job:0349| Persistent state global_properties.tag now set to ''
08/02 11:06:58 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:06:58 INFO |server_job:0534| Processing control file
08/02 11:06:58 INFO |server_job:0536| Finished processing control file

Netperf logfile:

08/02 11:08:25 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/457-debug_user/group0
08/02 11:08:25 DEBUG| base_job:0349| Persistent state global_properties.tag now set to '457-debug_user/group0'
08/02 11:08:25 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:08:25 INFO |server_job:0534| Processing control file
08/02 11:08:25 INFO |server_job:0117| START netperf2 netperf2 timestamp=1343905705 localtime=Aug 02 11:08:25
08/02 11:08:25 INFO | netperf2:0008| running on test-client1 and test-client2
08/02 11:08:25 INFO | netperf2:0008|
08/02 11:08:25 DEBUG|base_utils:0077| Running '/usr/local/autotest/conmux/conmux-attach test-client1 echo 2> /dev/null'
08/02 11:08:25 DEBUG| ssh_host:0114| Running (ssh) 'ls /var/log/kern.log'
08/02 11:08:25 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:08:25 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:08:25 DEBUG|base_utils:0114| [stderr] Warning: Permanently added 'test-client1,192.168.254.11' (ECDSA) to the list of known hosts.
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /var/log/kern.log
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /var/tmp'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /var/tmp/autoserv-XXXXXX'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /var/tmp/autoserv-TgXFIh
08/02 11:08:26 INFO |logfile_mo:0052| Launching followfiles on target: test-client1, /var/tmp/autoserv-TgXFIh, ['/var/log/kern.log']
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/bin/python[0-9]'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /usr/bin/python2
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /usr/bin/python2.7
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-57JcML
08/02 11:08:26 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:08:26 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:26 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/server/hosts/monitors root@test-client1:"/tmp/autoserv-57JcML"'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:08:26 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:08:26 DEBUG|base_utils:0077| Running '/usr/local/autotest/conmux/conmux-attach test-client2 echo 2> /dev/null'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'ls /var/log/kern.log'
08/02 11:08:26 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client2'
08/02 11:08:26 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client2'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /var/log/kern.log
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /var/tmp'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /var/tmp/autoserv-XXXXXX'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /var/tmp/autoserv-pk2k6t
08/02 11:08:26 INFO |logfile_mo:0052| Launching followfiles on target: test-client2, /var/tmp/autoserv-pk2k6t, ['/var/log/kern.log']
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/bin/python[0-9]'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /usr/bin/python2
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /usr/bin/python2.7
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:08:26 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-vugbtn
08/02 11:08:26 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:08:26 INFO |abstract_s:0117| XMARKWA make_rsync_cmd
08/02 11:08:26 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/server/hosts/monitors root@test-client2:"/tmp/autoserv-vugbtn"'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:08:26 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:08:26 DEBUG| ssh_host:0114| Running (ssh) '/sbin/iptables -L'
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain INPUT (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG|base_utils:0114| [stdout]
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain FORWARD (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG|base_utils:0114| [stdout]
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain OUTPUT (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables-save > /tmp/iptable-rules'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P INPUT ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P FORWARD ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P OUTPUT ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) '/sbin/iptables -L'
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain INPUT (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG|base_utils:0114| [stdout]
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain FORWARD (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG|base_utils:0114| [stdout]
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Chain OUTPUT (policy ACCEPT)
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables-save > /tmp/iptable-rules'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P INPUT ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P FORWARD ACCEPT'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'iptables -P OUTPUT ACCEPT'
08/02 11:08:27 DEBUG|base_utils:0077| Running 'tools/make_clean'
08/02 11:08:27 DEBUG|base_utils:0077| Running 'tools/make_clean'
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] rm: cannot remove network_EthernetStressPlug/src': Permission denied 08/02 11:08:27 DEBUG|base_utils:0114| [stderr] rm: cannot removetmp/.testlock': Permission denied
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] rm: cannot remove network_EthernetStressPlug/src': Permission denied 08/02 11:08:27 DEBUG|base_utils:0114| [stderr] rm: cannot removetmp/.testlock': Permission denied
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning rmaptest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning disktest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning ipv6connect test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning signaltest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning rmaptest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning iosched_bugs test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning tracing_microbenchmark test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning disktest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning synctest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning ipv6connect test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning cyclictest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning signaltest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning rtc test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning iosched_bugs test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning aio_dio_bugs test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning tracing_microbenchmark test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning hackbench test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning synctest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning monotonic_time test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning cyclictest test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning tsc test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning rtc test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning aio_dio_bugs test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning hackbench test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning monotonic_time test dir
08/02 11:08:27 DEBUG|base_utils:0114| [stdout] Cleaning tsc test dir
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:08:27 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:08:27 INFO |autotest_r:0224| Installing autotest on test-client1
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'test -x /usr/local/autotest/autotest'
08/02 11:08:27 DEBUG|abstract_s:0458| Host test-client2 is now up
08/02 11:08:27 INFO |autotest_r:0224| Installing autotest on test-client2
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'test -x /usr/local/autotest/autotest'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'test -w /usr/local/autotest'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'test -w /usr/local/autotest'
08/02 11:08:27 DEBUG|autotest_r:0073| Found existing autodir at /usr/local/autotest
08/02 11:08:27 INFO |autotest_r:0229| Using installation dir /usr/local/autotest
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest'
08/02 11:08:27 DEBUG|autotest_r:0073| Found existing autodir at /usr/local/autotest
08/02 11:08:27 INFO |autotest_r:0229| Using installation dir /usr/local/autotest
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'rm -rf /usr/local/autotest/results/'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'rm -rf /usr/local/autotest/results/'
08/02 11:08:27 INFO |autotest_r:0249| Could not install autotest using the packaging system: No repos to install an autotest client from. Trying other methods
08/02 11:08:27 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:27 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:27 DEBUG|base_utils:0077| Running 'rsync -L --delete --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/client/tmp /usr/local/autotest/client/setup.py /usr/local/autotest/client/fsdev_disks.py /usr/local/autotest/client/job_unittest.py /usr/local/autotest/client/utils.pyc /usr/local/autotest/client/package.py /usr/local/autotest/client/harness_standalone.py /usr/local/autotest/client/local_host_unittest.py /usr/local/autotest/client/optparser.py /usr/local/autotest/client/os_dep.pyc /usr/local/autotest/client/kernel.pyc /usr/local/autotest/client/job.py /usr/local/autotest/client/common.pyc /usr/local/autotest/client/kernelexpand.py /usr/local/autotest/client/kernel.py /usr/local/autotest/client/setup_job.pyc /usr/local/autotest/client/autotest_local.py /usr/local/autotest/client/autotest_local.pyc /usr/local/autotest/client/fsinfo_unittest.py /usr/local/autotest/client/fsinfo.py /usr/local/autotest/client/base_utils.pyc /usr/local/autotest/client/local_host.py /usr/local/autotest/client/pyudev-0.15 /usr/local/autotest/client/client_logging_config.py /usr/local/autotest/client/job.pyc /usr/local/autotest/client/setup_modules.pyc /usr/local/autotest/client/os_dep.py /usr/local/autotest/client/kvm_control.py /usr/local/autotest/client/harness_autoserv.py /usr/local/autotest/client/setup_job_unittest.py /usr/local/autotest/client/cmdparser.py /usr/local/autotest/client/partition.py /usr/local/autotest/client/package_unittest.py /usr/local/autotest/client/autotestd_monitor /usr/local/autotest/client/base_utils.py /usr/local/autotest/client/partition.pyc /usr/local/autotest/client/harness_ABAT.py /usr/local/autotest/client/fsdev_mgr.py /usr/local/autotest/client/xen.pyc /usr/local/autotest/client/harness_unittest.py /usr/local/autotest/client/xen.py /usr/local/autotest/client/autotest_client /usr/local/autotest/client/results /usr/local/autotest/client/kernelexpand_unittest.py /usr/local/autotest/client/kernel_versions.py /usr/local/autotest/client/utils.py /usr/local/autotest/client/config.py /usr/local/autotest/client/kernel_versions_unittest.py /usr/local/autotest/client/client_logging_config.pyc /usr/local/autotest/client/base_sysinfo.pyc /usr/local/autotest/client/cmdparser.pyc /usr/local/autotest/client/test_config.py /usr/local/autotest/client/boottool.pyc /usr/local/autotest/client/partition_unittest.py /usr/local/autotest/client/local_host.pyc /usr/local/autotest/client/profiler.py /usr/local/autotest/client/net /usr/local/autotest/client/test.py /usr/local/autotest/client/parallel.pyc /usr/local/autotest/client/kernel_unittest.py /usr/local/autotest/client/harness.pyc /usr/local/autotest/client/LICENSE /usr/local/autotest/client/optparser.pyc /usr/local/autotest/client/TODO /usr/local/autotest/client/sysinfo.py /usr/local/autotest/client/harness_standalone.pyc /usr/local/autotest/client/harness_simple.py /usr/local/autotest/client/kernel_config.pyc /usr/local/autotest/client/setup_job.py /usr/local/autotest/client/virt /usr/local/autotest/client/fsdev_disks_unittest.py /usr/local/autotest/client/init.py /usr/local/autotest/client/common.py /usr/local/autotest/client/autotest /usr/local/autotest/client/harness.py /usr/local/autotest/client/cpuset.py /usr/local/autotest/client/tools /usr/local/autotest/client/init.pyc /usr/local/autotest/client/base_sysinfo.py /usr/local/autotest/client/autotestd /usr/local/autotest/client/setup_modules.py /usr/local/autotest/client/kernel_config.py /usr/local/autotest/client/package.pyc /usr/local/autotest/client/config /usr/local/autotest/client/test.pyc /usr/local/autotest/client/kernelexpand.pyc /usr/local/autotest/client/samples /usr/local/autotest/client/parallel.py /usr/local/autotest/client/autotest-local /usr/local/autotest/client/shared /usr/local/autotest/client/setup_modules_unittest.py /usr/local/autotest/client/sysinfo.pyc /usr/local/autotest/client/config.pyc /usr/local/autotest/client/deps/grubby/grubby-8.15.tar.bz2 root@test-client1:"/usr/local/autotest"'
08/02 11:08:27 INFO |autotest_r:0249| Could not install autotest using the packaging system: No repos to install an autotest client from. Trying other methods
08/02 11:08:27 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:27 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:27 DEBUG|base_utils:0077| Running 'rsync -L --delete --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/client/tmp /usr/local/autotest/client/setup.py /usr/local/autotest/client/fsdev_disks.py /usr/local/autotest/client/job_unittest.py /usr/local/autotest/client/utils.pyc /usr/local/autotest/client/package.py /usr/local/autotest/client/harness_standalone.py /usr/local/autotest/client/local_host_unittest.py /usr/local/autotest/client/optparser.py /usr/local/autotest/client/os_dep.pyc /usr/local/autotest/client/kernel.pyc /usr/local/autotest/client/job.py /usr/local/autotest/client/common.pyc /usr/local/autotest/client/kernelexpand.py /usr/local/autotest/client/kernel.py /usr/local/autotest/client/setup_job.pyc /usr/local/autotest/client/autotest_local.py /usr/local/autotest/client/autotest_local.pyc /usr/local/autotest/client/fsinfo_unittest.py /usr/local/autotest/client/fsinfo.py /usr/local/autotest/client/base_utils.pyc /usr/local/autotest/client/local_host.py /usr/local/autotest/client/pyudev-0.15 /usr/local/autotest/client/client_logging_config.py /usr/local/autotest/client/job.pyc /usr/local/autotest/client/setup_modules.pyc /usr/local/autotest/client/os_dep.py /usr/local/autotest/client/kvm_control.py /usr/local/autotest/client/harness_autoserv.py /usr/local/autotest/client/setup_job_unittest.py /usr/local/autotest/client/cmdparser.py /usr/local/autotest/client/partition.py /usr/local/autotest/client/package_unittest.py /usr/local/autotest/client/autotestd_monitor /usr/local/autotest/client/base_utils.py /usr/local/autotest/client/partition.pyc /usr/local/autotest/client/harness_ABAT.py /usr/local/autotest/client/fsdev_mgr.py /usr/local/autotest/client/xen.pyc /usr/local/autotest/client/harness_unittest.py /usr/local/autotest/client/xen.py /usr/local/autotest/client/autotest_client /usr/local/autotest/client/results /usr/local/autotest/client/kernelexpand_unittest.py /usr/local/autotest/client/kernel_versions.py /usr/local/autotest/client/utils.py /usr/local/autotest/client/config.py /usr/local/autotest/client/kernel_versions_unittest.py /usr/local/autotest/client/client_logging_config.pyc /usr/local/autotest/client/base_sysinfo.pyc /usr/local/autotest/client/cmdparser.pyc /usr/local/autotest/client/test_config.py /usr/local/autotest/client/boottool.pyc /usr/local/autotest/client/partition_unittest.py /usr/local/autotest/client/local_host.pyc /usr/local/autotest/client/profiler.py /usr/local/autotest/client/net /usr/local/autotest/client/test.py /usr/local/autotest/client/parallel.pyc /usr/local/autotest/client/kernel_unittest.py /usr/local/autotest/client/harness.pyc /usr/local/autotest/client/LICENSE /usr/local/autotest/client/optparser.pyc /usr/local/autotest/client/TODO /usr/local/autotest/client/sysinfo.py /usr/local/autotest/client/harness_standalone.pyc /usr/local/autotest/client/harness_simple.py /usr/local/autotest/client/kernel_config.pyc /usr/local/autotest/client/setup_job.py /usr/local/autotest/client/virt /usr/local/autotest/client/fsdev_disks_unittest.py /usr/local/autotest/client/init.py /usr/local/autotest/client/common.py /usr/local/autotest/client/autotest /usr/local/autotest/client/harness.py /usr/local/autotest/client/cpuset.py /usr/local/autotest/client/tools /usr/local/autotest/client/init.pyc /usr/local/autotest/client/base_sysinfo.py /usr/local/autotest/client/autotestd /usr/local/autotest/client/setup_modules.py /usr/local/autotest/client/kernel_config.py /usr/local/autotest/client/package.pyc /usr/local/autotest/client/config /usr/local/autotest/client/test.pyc /usr/local/autotest/client/kernelexpand.pyc /usr/local/autotest/client/samples /usr/local/autotest/client/parallel.py /usr/local/autotest/client/autotest-local /usr/local/autotest/client/shared /usr/local/autotest/client/setup_modules_unittest.py /usr/local/autotest/client/sysinfo.pyc /usr/local/autotest/client/config.pyc /usr/local/autotest/client/deps/grubby/grubby-8.15.tar.bz2 root@test-client2:"/usr/local/autotest"'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest/profilers'
08/02 11:08:27 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:27 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:27 DEBUG|base_utils:0077| Running 'rsync -L --delete --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/client/profilers/init.py root@test-client1:"/usr/local/autotest/profilers"'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p '/usr/local/autotest/site_tests';touch '/usr/local/autotest/site_tests'/init.py;mkdir -p '/usr/local/autotest/tests';touch '/usr/local/autotest/tests'/init.py;mkdir -p '/usr/local/autotest/deps';touch '/usr/local/autotest/deps'/init.py'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest/tmp'
08/02 11:08:27 INFO |autotest_r:0262| Installation of autotest completed
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:08:27 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:08:27 DEBUG|autotest_r:0065| Using existing host autodir: /usr/local/autotest
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/local/autotest/autotest > /dev/null 2>&1'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tmp'
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tmp: not mounted
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tests/download'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest/profilers'
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tests/download: not mounted
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/local/autotest/autotest > /dev/null 2>&1'
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tmp'
08/02 11:08:27 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:27 INFO |abstract_s:0117| XMARKWA make_rsync_cmd
08/02 11:08:27 DEBUG|base_utils:0077| Running 'rsync -L --delete --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/client/profilers/init.py root@test-client2:"/usr/local/autotest/profilers"'
08/02 11:08:27 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tmp: not mounted
08/02 11:08:27 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tests/download'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tests/download: not mounted
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /usr/local/autotest/control.autoserv;rm -f /usr/local/autotest/tmp/control.autoserv.state;rm -f /usr/local/autotest/control;rm -f /usr/local/autotest/tmp/control.state'
08/02 11:08:28 DEBUG| base_job:0349| Persistent state client.sysinfo now set to {'test': set([sysinfo.command('dmesg -c', 'dmesg', False), sysinfo.command('df -mP', 'df', False)]), 'boot': set([sysinfo.command('gcc --version', 'gcc--version', False), sysinfo.command('ld --version', 'ld--version', False), sysinfo.logfile('/proc/partitions', 'partitions', False), sysinfo.logfile('/proc/interrupts', 'interrupts', False), sysinfo.command('hostname', 'hostname', False), sysinfo.command('mount', 'mount', False), sysinfo.logfile('/proc/cmdline', 'cmdline', True), sysinfo.logfile('/proc/version', 'version', False), sysinfo.command('lspci -vvn', 'lspci-vvn', False), sysinfo.logfile('/proc/slabinfo', 'slabinfo', False), sysinfo.logfile('/proc/modules', 'modules', False), sysinfo.logfile('/proc/mounts', 'proc_mounts', False), sysinfo.logfile('/proc/cpuinfo', 'cpuinfo', False), sysinfo.command('uptime', 'uptime', False), sysinfo.logfile('/proc/pci', 'pci', False), sysinfo.logfile('/proc/meminfo', 'meminfo', False), sysinfo.command('uname -a', 'uname', True)])}
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/tmpsjKk2S root@test-client1:"/usr/local/autotest/tmp/control.autoserv.init.state"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p '/usr/local/autotest/site_tests';touch '/usr/local/autotest/site_tests'/init.py;mkdir -p '/usr/local/autotest/tests';touch '/usr/local/autotest/tests'/init.py;mkdir -p '/usr/local/autotest/deps';touch '/usr/local/autotest/deps'/init.py'
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /tmp/autoserv-PD15m7/tmpagBt6q root@test-client1:"/usr/local/autotest/control.autoserv"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /usr/local/autotest/tmp'
08/02 11:08:28 INFO |autotest_r:0262| Installation of autotest completed
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:08:28 DEBUG|abstract_s:0458| Host test-client2 is now up
08/02 11:08:28 DEBUG|autotest_r:0065| Using existing host autodir: /usr/local/autotest
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/local/autotest/autotest > /dev/null 2>&1'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tmp'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:08:28 DEBUG|base_utils:0114| [stdout] 07f6f514-affe-4104-a182-6c81f91e20b6
08/02 11:08:28 INFO |autotest_r:0707| Executing /usr/local/autotest/autotest /usr/local/autotest/control phase 0
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tmp: not mounted
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tests/download'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tests/download: not found
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'ls /usr/local/autotest/autotest > /dev/null 2>&1'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tmp'
08/02 11:08:28 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-kb9Rhe
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/tmpC_WFZN root@test-client1:"/usr/local/autotest/global_config.ini"'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tmp: not mounted
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'umount /usr/local/autotest/tests/download'
08/02 11:08:28 DEBUG|base_utils:0114| [stderr] umount: /usr/local/autotest/tests/download: not found
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /usr/local/autotest/control.autoserv;rm -f /usr/local/autotest/tmp/control.autoserv.state;rm -f /usr/local/autotest/control;rm -f /usr/local/autotest/tmp/control.state'
08/02 11:08:28 DEBUG| base_job:0349| Persistent state client.sysinfo now set to {'test': set([sysinfo.command('dmesg -c', 'dmesg', False), sysinfo.command('df -mP', 'df', False)]), 'boot': set([sysinfo.command('gcc --version', 'gcc--version', False), sysinfo.command('ld --version', 'ld--version', False), sysinfo.logfile('/proc/partitions', 'partitions', False), sysinfo.logfile('/proc/interrupts', 'interrupts', False), sysinfo.command('hostname', 'hostname', False), sysinfo.command('mount', 'mount', False), sysinfo.logfile('/proc/cmdline', 'cmdline', True), sysinfo.logfile('/proc/version', 'version', False), sysinfo.command('lspci -vvn', 'lspci-vvn', False), sysinfo.logfile('/proc/slabinfo', 'slabinfo', False), sysinfo.logfile('/proc/modules', 'modules', False), sysinfo.logfile('/proc/mounts', 'proc_mounts', False), sysinfo.logfile('/proc/cpuinfo', 'cpuinfo', False), sysinfo.command('uptime', 'uptime', False), sysinfo.logfile('/proc/pci', 'pci', False), sysinfo.logfile('/proc/meminfo', 'meminfo', False), sysinfo.command('uname -a', 'uname', True)])}
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/tmpXLkxvl root@test-client2:"/usr/local/autotest/tmp/control.autoserv.init.state"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'nohup /usr/local/autotest/autotestd /tmp/autoserv-kb9Rhe -H autoserv --verbose --hostname=test-client1 --user=debug_user /usr/local/autotest/control.autoserv >/dev/null 2>/dev/null &'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) '/usr/local/autotest/autotestd_monitor /tmp/autoserv-kb9Rhe 0 0'
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /tmp/autoserv-SJhcnl/tmpg_mx8s root@test-client2:"/usr/local/autotest/control.autoserv"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'if [ -f '/proc/sys/kernel/random/boot_id' ]; then cat '/proc/sys/kernel/random/boot_id'; else echo 'no boot_id available'; fi'
08/02 11:08:28 DEBUG|base_utils:0114| [stdout] ab083a36-5d60-485b-b808-8d21d54473a5
08/02 11:08:28 INFO |autotest_r:0707| Executing /usr/local/autotest/autotest /usr/local/autotest/control phase 0
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mkdir -p /tmp'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'mktemp -d /tmp/autoserv-XXXXXX'
08/02 11:08:28 DEBUG|base_utils:0114| [stdout] /tmp/autoserv-atrOMr
08/02 11:08:28 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:28 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:28 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/tmp5twp7J root@test-client2:"/usr/local/autotest/global_config.ini"'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) 'nohup /usr/local/autotest/autotestd /tmp/autoserv-atrOMr -H autoserv --verbose --hostname=test-client2 --user=debug_user /usr/local/autotest/control.autoserv >/dev/null 2>/dev/null &'
08/02 11:08:28 DEBUG| ssh_host:0114| Running (ssh) '/usr/local/autotest/autotestd_monitor /tmp/autoserv-atrOMr 0 0'
08/02 11:08:29 INFO |server_job:0117| START ---- ---- timestamp=1343905709 localtime=Aug 02 11:08:29
08/02 11:08:29 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_12n74Wharness-fifo/autoserv.fifo'
08/02 11:08:29 INFO |server_job:0117| START netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905709 localtime=Aug 02 11:08:29
08/02 11:08:29 INFO |server_job:0117| START ---- ---- timestamp=1343905709 localtime=Aug 02 11:08:29
08/02 11:08:29 INFO |autotest_r:1030| Bundling /usr/local/autotest/client/tests/netperf2 into test-netperf2.tar.bz2
08/02 11:08:29 DEBUG|base_utils:0077| Running 'tar -cf /usr/local/autotest/tmp/tmp/_autotmp_ZuY462autoserv-packager/test-netperf2.tar.bz2.tmp -C /usr/local/autotest/client/tests/netperf2 -j .'
08/02 11:08:29 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_I53cMEharness-fifo/autoserv.fifo'
08/02 11:08:29 INFO |server_job:0117| START netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905709 localtime=Aug 02 11:08:29
08/02 11:08:29 INFO |autotest_r:1030| Bundling /usr/local/autotest/client/tests/netperf2 into test-netperf2.tar.bz2
08/02 11:08:29 DEBUG|base_utils:0077| Running 'tar -cf /usr/local/autotest/tmp/tmp/_autotmp_Q1PuQ_autoserv-packager/test-netperf2.tar.bz2.tmp -C /usr/local/autotest/client/tests/netperf2 -j .'
08/02 11:08:30 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:30 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:30 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/_autotmp_ZuY462autoserv-packager/test-netperf2.tar.bz2 root@test-client1:"/usr/local/autotest/tmp/packages/test-netperf2.tar.bz2"'
08/02 11:08:30 INFO |abstract_s:0345| XMARKWA send_file
08/02 11:08:30 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:08:30 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az /usr/local/autotest/tmp/tmp/_autotmp_Q1PuQ_autoserv-packager/test-netperf2.tar.bz2 root@test-client2:"/usr/local/autotest/tmp/packages/test-netperf2.tar.bz2"'
08/02 11:08:30 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_xFyDQnharness-fifo/autoserv.fifo'
08/02 11:08:30 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_Fsz9Urharness-fifo/autoserv.fifo'
08/02 11:08:31 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_OUjZZQharness-fifo/autoserv.fifo'
08/02 11:08:31 DEBUG| ssh_host:0114| Running (ssh) 'echo B > /usr/local/autotest/tmp/tmp/_autotmp_vh0e9Pharness-fifo/autoserv.fifo'
08/02 11:09:15 INFO |server_job:0117| GOOD netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905755 localtime=Aug 02 11:09:15 completed successfully
08/02 11:09:15 INFO |server_job:0117| GOOD netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905754 localtime=Aug 02 11:09:14 completed successfully
08/02 11:09:15 INFO |server_job:0117| END GOOD netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905755 localtime=Aug 02 11:09:15
08/02 11:09:15 INFO |server_job:0117| END GOOD netperf2.TCP_STREAM netperf2.TCP_STREAM timestamp=1343905754 localtime=Aug 02 11:09:14
08/02 11:09:15 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:09:15 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:09:15 DEBUG|abstract_s:0458| Host test-client2 is now up
08/02 11:09:15 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:09:15 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:09:15 DEBUG|base_utils:0077| Running 'rsync --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/usr/local/autotest/results/default/" /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2'
08/02 11:09:15 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:09:15 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:09:15 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:09:15 DEBUG|base_utils:0077| Running 'rsync --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/usr/local/autotest/results/default/" /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1'
08/02 11:09:15 DEBUG| ssh_host:0114| Running (ssh) 'echo A > /usr/local/autotest/tmp/tmp/_autotmp_ZpyZREharness-fifo/autoserv.fifo'
08/02 11:09:15 DEBUG| ssh_host:0114| Running (ssh) 'echo A > /usr/local/autotest/tmp/tmp/_autotmp_hkbDeeharness-fifo/autoserv.fifo'
08/02 11:09:15 INFO |server_job:0117| END GOOD ---- ---- timestamp=1343905755 localtime=Aug 02 11:09:15
08/02 11:09:15 INFO |server_job:0117| END GOOD ---- ---- timestamp=1343905755 localtime=Aug 02 11:09:15
08/02 11:09:17 INFO |autotest_r:0792| Client complete
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:09:17 INFO |autotest_r:0792| Client complete
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:09:17 DEBUG|abstract_s:0458| Host test-client2 is now up
08/02 11:09:17 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:09:17 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:09:17 DEBUG|base_utils:0077| Running 'rsync --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_D0QVLBssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpTbtU2N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/usr/local/autotest/results/default/" /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2'
08/02 11:09:17 DEBUG|abstract_s:0458| Host test-client1 is now up
08/02 11:09:17 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:09:17 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:09:17 DEBUG|base_utils:0077| Running 'rsync --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_AntoIassh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp00VI8N -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/usr/local/autotest/results/default/" /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1'
08/02 11:09:17 DEBUG| base_job:0242| Value of client.sysinfo is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0245| Importing client.harness from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0245| Importing client.steps from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0245| Importing client._record_indent from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client2/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0242| Value of global_properties.tag is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0242| Value of global_properties.last_boot_tag is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0391| Persistent state client.* deleted
08/02 11:09:17 DEBUG| base_job:0242| Value of client.sysinfo is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0245| Importing client.harness from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0245| Importing client.steps from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0245| Importing client._record_indent from state file /usr/local/autotest/results/457-debug_user/group0/netperf2/test-client1/control.autoserv.state
08/02 11:09:17 DEBUG| base_job:0242| Value of global_properties.tag is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0242| Value of global_properties.last_boot_tag is unchanged, skipping import
08/02 11:09:17 DEBUG| base_job:0391| Persistent state client.* deleted
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) '/sbin/iptables -L'
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain INPUT (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG|base_utils:0114| [stdout]
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain FORWARD (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG|base_utils:0114| [stdout]
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain OUTPUT (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'ls "/tmp/iptable-rules" > /dev/null'
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'iptables-restore < /tmp/iptable-rules'
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) '/sbin/iptables -L'
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain INPUT (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG|base_utils:0114| [stdout]
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain FORWARD (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG|base_utils:0114| [stdout]
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] Chain OUTPUT (policy ACCEPT)
08/02 11:09:17 DEBUG|base_utils:0114| [stdout] target prot opt source destination
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'ls "/tmp/iptable-rules" > /dev/null'
08/02 11:09:17 DEBUG| ssh_host:0114| Running (ssh) 'iptables-restore < /tmp/iptable-rules'
08/02 11:21:57 INFO | autoserv:0201| Results placed in /usr/local/autotest/results/457-debug_user/group0
08/02 11:21:57 DEBUG| base_job:0349| Persistent state global_properties.tag now set to ''
08/02 11:21:57 DEBUG| base_job:0349| Persistent state global_properties.last_boot_tag now set to None
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:21:57 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_RI7quYssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpX63eQ6 -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:21:57 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_RI7quYssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpX63eQ6 -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client1'
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'test -f /var/log/messages'
08/02 11:21:57 INFO |abstract_s:0618| Starting master ssh connection '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client2'
08/02 11:21:57 DEBUG|base_utils:0077| Running '/usr/bin/ssh -a -x -N -o ControlMaster=yes -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22 test-client2'
08/02 11:21:57 ERROR|base_utils:0114| [stderr] Warning: Permanently added 'test-client2,192.168.254.12' (ECDSA) to the list of known hosts.
08/02 11:21:57 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:21:57 DEBUG| remote:0185| Found remote path /var/log/messages
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'rm -f /var/tmp/messages.autotest_start'
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:21:57 INFO |crashcolle:0021| Collecting crash information...
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'cp /var/log/messages /var/tmp/messages.autotest_start'
08/02 11:21:57 INFO |crashcolle:0052| test-client2 already up, collecting crash info
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/tmp/messages.autotest_start...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:21:57 INFO |crashcolle:0021| Collecting crash information...
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'true'
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/var/tmp/messages.autotest_start" /usr/local/autotest/results/457-debug_user/group0/crashinfo.test-client2/messages.at_start'
08/02 11:21:57 INFO |crashcolle:0052| test-client1 already up, collecting crash info
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/tmp/messages.autotest_start...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 DEBUG| ssh_host:0114| Running (ssh) 'rsync --version'
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_RI7quYssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpX63eQ6 -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/tmp/messages.autotest_start" /usr/local/autotest/results/457-debug_user/group0/crashinfo.test-client1/messages.at_start'
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/log/messages...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/var/log/messages" /usr/local/autotest/results/457-debug_user/group0/crashinfo.test-client2/messages.raw'
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/log/messages...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_RI7quYssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmpX63eQ6 -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client1:"/var/log/messages" /usr/local/autotest/results/457-debug_user/group0/crashinfo.test-client1/messages.raw'
08/02 11:21:57 INFO |crashcolle:0099| Collecting /var/log/monitor-ssh-reboots...
08/02 11:21:57 INFO |abstract_s:0240| XMARKWA get_file
08/02 11:21:57 INFO |abstract_s:0117| XMARKWA _make_rsync_cmd
08/02 11:21:57 DEBUG|base_utils:0077| Running 'rsync -L --timeout=1800 --rsh='/usr/bin/ssh -a -x -o ControlPath=/tmp/_autotmp_dEdIc_ssh-master/socket -o StrictHostKeyChecking=no -o UserKnownHostsFile=/tmp/tmp2XIgSf -o BatchMode=yes -o ConnectTimeout=30 -o ServerAliveInterval=300 -l root -p 22' -az root@test-client2:"/var/log/monitor-ssh-reboots" /usr/local/autotest/results/457-debug_user/group0/crashinfo

This version provide base test of virsh schedinfo command:
virsh schedinfo [--set <set_ref>]
TODO:to support more parameters...

1. Prepare test environment.
2. Run test case according schedinfo's configration.
3. Recover test environment
4. Check Result.

Hi guys,

when developing a Windows test I got a lot of No DHCP lease for MAC 9a:2b:2c:2d:2e:2f or ...can't verify address... messages. Followed by can't connect to guest test failures.

The problem is 100% reproducible (on my laptop):

1. Execute any test on Windows XP
2. killall qemu-kvm, rm -f env, rm -f /tmp/address_poll*
3. Execute any test on Windows XP

There is a simple fix, login to the machine (vnc or nc with the old IP address) and run "ipconfig /renew". It returns error:
An error occurred while renewing interface Local Area Connection 5 : Access is denied. or
An error occurred while renewing interface Local Area Connection 5 : Unable to contact your DHCP server. Request has timed out.
but the IP address changes successfully and is recognized by autotest.

Funny was that by using GUI Control Panel -> Network Connections -> Local Area ... -> Support -> Repair didn't work, but cmd ipconfig /renew did.

My idea is that windows won't send dhcp request on boot when the old (previous run) address is still valid. But don't take me seriously, I don't understand Windows...

My laptop: Fedora 17, qemu-kvm-1.0.1-1.fc17.x86_64, current autotest git-next
Guest: Windows XP SP3

PS: I sometimes encounter broken bridge which requires to stop and start bridge (in virt-manager) and then everything works fine. This is not the case and bridge restart doesn't help.

This patch series integrate OpenVSwitch to autotest.
Adds possibility manipulate with bridge and OpenVSwitch directly from tests.

This version provide base test of virsh schedinfo command:
virsh schedinfo [--set <set_ref>]
TODO:to support more parameters...

1. Prepare test environment.
2. Run test case according schedinfo's configration.
3. Recover test environment
4. Check Result.

This version provide base test of virsh schedinfo command:
virsh schedinfo [--set <set_ref>]
TODO:to support more parameters...

1. Prepare test environment.
2. Run test case according schedinfo's configration.
3. Recover test environment
4. Check Result.

As the win guest driver is getting more huge, the virtio-win.vfd is now increased to 2.88M.
Let's increase vfd in autotest to 2.88M too.

This patchset tests virsh command setmem.
virsh setmem can reset domain's memroy currently.

1. Prepare vm environment.
2. Prepare libvirt state.
3. Run test command and wait for current memory's stable.
4. Check result.
   TODO: support new libvirt with more options.

It was pointed out by Liu Sheng [email protected] that in several places we have architecture dependent code in the kvm/virt tests in general. He suggested to develop mechanisms to abstract arch specific code in an organized and centralized way. In his words:

And I find so many arch related codes are in so many files of kvm autotest and
autotest itself, most of them are in if-else style. As more and more arch will
support kvm, and some cases maybe arch related, it will be hard to manage the
arch related code. Can we have some infrastructure code to put them together and
give a uniform interface. Just like it is in linux kernel, the arch related code
are in arch dir, not in every .c file.

This issue tracks possible implementations for this future. Unfortunately nothing occurs to me in terms of implementation, so if someone has an idea, please manifest yourself :)

Comment will be updated soon

As the win guest driver is getting more huge, the virtio-win.vfd is now increased to 2.88M.
Let's increase vfd in autotest to 2.88M too.

Test the virsh cpu-stats command

(1) Invoke virsh cpu-stats <domain> <options>
(2) Invoke virsh cpu-stats with following possible combination of options
         a. None      e. --start --count
         b. --start   f. --start --total
         c. --count   g. --count --total
         d. --total   h. --start --count --total
(3) Invoke virsh cpu-stats with a numeric argument
(4) Invoke virsh cpu-stats with an invalid string "xyz"
(5) Invoke virsh cpu-stats with above combinations with libvitrd service

stop

Pass Condition:

1. When option = 'total'
   a. Displayed Total cpu_time > User cpu_time > System cpu_time
   b. Displayed Total cpu_time >= User + System cpu_time
2. When option = 'start' or 'count'
   a. Displayed CPU's == Expected CPU's
   b. Cgroup cpu_time* >= sum of cpu_time of each cpu's displayed
3. When option has a combination of 'start', 'count', 'total'
   All the above conditions 1 & 2 are checked.
4. When option is None
   a. Displayed Total cpu_time >= sum of cpu_time of all cpu's displayed
   b. Pass condition when option = 'total' (1) is checked.

*Cgroup cpu_time is computed by reading domain specific cpuacct.usage_percpu
Delay in reading the percpu file will lead up to cgropu cpu_time being slightly
higher (in ns) than the displayed time.

I find there is no way to add profilers when creating a job using cli/atest.

So I changed the cli/job.py to add in the profiler related options.

diff job.py job_new.py

385a386,392

    self.parser.add_option('-r', '--profiler',
                           help='List of profiler to run')

    self.parser.add_option('--profile_only',
                           help='Whether or not run each test without profilers first',
                           default=False, action='store_true')

485a493,500
if options.profiler:
profilers = [t.strip() for t in options.profiler.split(',') if t.strip()]
self.ctrl_file_data['profilers'] = profilers

    if options.profile_only:
        self.ctrl_file_data['profile_only'] = True
    else:
        self.ctrl_file_data['profile_only'] = False

And now the cli/atest works well with profilers.

Test the virsh cpu-stats command

(1) Invoke virsh cpu-stats <domain> <options>
(2) Invoke virsh cpu-stats with following possible combination of options
         a. None      e. --start --count
         b. --start   f. --start --total
         c. --count   g. --count --total
         d. --total   h. --start --count --total
(3) Invoke virsh cpu-stats with a numeric argument
(4) Invoke virsh cpu-stats with an invalid string "xyz"
(5) Invoke virsh cpu-stats with above combinations with libvitrd service

stop

Pass Condition:

1. When option = 'total'
   a. Displayed Total cpu_time > User cpu_time > System cpu_time
   b. Displayed Total cpu_time >= User + System cpu_time
2. When option = 'start' or 'count'
   a. Displayed CPU's == Expected CPU's
   b. Cgroup cpu_time* >= sum of cpu_time of each cpu's displayed
3. When option has a combination of 'start', 'count', 'total'
   All the above conditions 1 & 2 are checked.
4. When option is None
   a. Displayed Total cpu_time >= sum of cpu_time of all cpu's displayed
   b. Pass condition when option = 'total' (1) is checked.

*Cgroup cpu_time is computed by reading domain specific cpuacct.usage_percpu
Delay in reading the percpu file will lead up to cgropu cpu_time being slightly
higher (in ns) than the displayed time.

This patch series integrate OpenVSwitch to autotest.
Adds possibility manipulate with bridge and OpenVSwitch directly from tests.

(1) Call the virsh nodememstats command
(2) Get the output
(3) Check the against /proc/meminfo output
(4) Call the virsh nodememstats command with an unexpected option
(5) Call the virsh nodememstats command with libvirtd service stop

(1) Call the virsh nodememstats command
(2) Get the output
(3) Check the against /proc/meminfo output
(4) Call the virsh nodememstats command with an unexpected option
(5) Call the virsh nodememstats command with libvirtd service stop