Ticket #96 (closed issue: fixed)

Opened 10 months ago

Last modified 10 months ago

When trying to run make test for HC::Manager, HC::Manager::VM tests fail.

Reported by: mbridges Assigned to: kindlund
Priority: normal Milestone: 0.9
Component: HoneyClient::Manager::VM Version: 0.99
Severity: none Keywords: vmware, server, delay, make, test, error, centos, chown, getIPaddrVM, #81
Cc:

Description

Whenever I try to make test for this module I try to do the test and they just wont run so I have to use perl -Ilib/ t/honeyclient_manager_vm.t and I am getting multiple errors, any help on how to resolve these errors? This is on CentOS 5. 

[root@localhost HoneyClient-Manager-0.99]# perl Makefile.PL
*** Module::AutoInstall version 1.02
*** Checking for Perl dependencies...
[Core Features]
- Carp                          ...loaded. (1.04)
- Config                        ...loaded. (0)
- Config::General               ...loaded. (2.33)
- Data::Dumper                  ...loaded. (2.121_08)
- DateTime::HiRes               ...loaded. (0.01)
- Digest::MD5                   ...loaded. (2.36)
- English                       ...loaded. (1.02)
- ExtUtils::MakeMaker           ...loaded. (6.36)
- Fcntl                         ...loaded. (1.05)
- File::Basename                ...loaded. (2.74)
- File::Copy                    ...loaded. (2.09)
- File::Copy::Recursive         ...loaded. (0.35)
- File::stat                    ...loaded. (1.00)
- FileHandle                    ...loaded. (2.01)
- HoneyClient::Util::Config     ...loaded. (0.98)
- HoneyClient::Util::SOAP       ...loaded. (0.98)
- IO::File                      ...loaded. (1.13)
- IPTables::IPv4                ...loaded. (0.98)
- Log::Log4perl                 ...loaded. (1.12)
- MIME::Base64                  ...loaded. (3.07)
- Net::DNS::Resolver            ...loaded. (614)
- POSIX                         ...loaded. (1.09)
- Proc::ProcessTable            ...loaded. (0.41)
- Storable                      ...loaded. (2.15)
- Thread::Queue                 ...loaded. (2.00)
- Thread::Semaphore             ...loaded. (2.01)
- Tie::File                     ...loaded. (0.97)
- Time::HiRes                   ...loaded. (1.86)
- VMware::VmPerl                ...loaded. (1.01)
- VMware::VmPerl::ConnectParams ...loaded. (1.01)
- VMware::VmPerl::Question      ...loaded. (1.01)
- VMware::VmPerl::Server        ...loaded. (1.01)
- VMware::VmPerl::VM            ...loaded. (1.01)
- sigtrap                       ...loaded. (1.02)
Warning, threads::shared has already been loaded.  To
enable shared variables, 'use threads' must be called
before threads::shared or any module that uses it.
- threads                       ...loaded. (1.65)
- threads::shared               ...loaded. (1.13)
*** Module::AutoInstall configuration finished.
Writing Makefile for HoneyClient::Manager
[root@localhost HoneyClient-Manager-0.99]# make
Manifying blib/man3/HoneyClient::Manager::VM::Clone.3pm
Manifying blib/man3/HoneyClient::Manager::VM.3pm
Manifying blib/man3/HoneyClient::Manager::FW.3pm
Manifying blib/man3/HoneyClient::Manager.3pm
[root@localhost HoneyClient-Manager-0.99]# make test
PERL_DL_NONLAZY=1 /usr/bin/perl "-MExtUtils::Command::MM" "-e" "test_harness(0, 'inc', 'blib/lib', 'blib/arch')" t/honeyclient_manager_vm.t
t/honeyclient_manager_vm....ok 4/0# About to run basic unit tests.           
# Note: These tests *expect* VMware Server or VMware GSX to be installed and running on this system beforehand.

t/honeyclient_manager_vm....ok 24/0Confused test output: test 25 answered after test 25
Confused test output: test 26 answered after test 26
Confused test output: test 27 answered after test 27
Confused test output: test 28 answered after test 28
Confused test output: test 29 answered after test 29
Confused test output: test 30 answered after test 30
Confused test output: test 31 answered after test 31
Confused test output: test 32 answered after test 32
Confused test output: test 33 answered after test 33
Confused test output: test 34 answered after test 34
Confused test output: test 35 answered after test 35
Confused test output: test 36 answered after test 36
Confused test output: test 37 answered after test 37
Confused test output: test 38 answered after test 38
Confused test output: test 39 answered after test 39
Confused test output: test 40 answered after test 40
Confused test output: test 41 answered after test 41
Confused test output: test 42 answered after test 42
Confused test output: test 43 answered after test 43
Confused test output: test 44 answered after test 44
Confused test output: test 45 answered after test 45
Confused test output: test 46 answered after test 46
Confused test output: test 47 answered after test 47
Confused test output: test 48 answered after test 48
Confused test output: test 49 answered after test 49
Confused test output: test 50 answered after test 50
Confused test output: test 51 answered after test 51
# About to run extended tests.
Confused test output: test 52 answered after test 52
# Note: These extended tests will take *significant* time to complete (10-30 minutes).

Don't know which tests failed: got 52 ok, expected 0
FAILED--1 test script could be run, alas--no output ever seen
make: *** [test_dynamic] Error 255
[root@localhost HoneyClient-Manager-0.99]# perl -Ilib/ t/honeyclient_manager_vm.t
ok 1 - use ExtUtils::MakeMaker;
ok 2 - use Log::Log4perl;
ok 3 - use HoneyClient::Util::Config;
ok 4 - use HoneyClient::Manager::VM;
ok 5 - use HoneyClient::Util::SOAP;
ok 6 - use File::Basename;
ok 7 - use File::Copy::Recursive;
ok 8 - use Data::Dumper;
ok 9 - use File::stat;
ok 10 - use Digest::MD5;
ok 11 - use DateTime::HiRes;
ok 12 - use Fcntl;
ok 13 - use VMware::VmPerl;
ok 14 - use VMware::VmPerl::Server;
ok 15 - use VMware::VmPerl::ConnectParams;
ok 16 - use VMware::VmPerl::VM;
ok 17 - use VMware::VmPerl::Question;
ok 18 - use threads;
ok 19 - use threads::shared;
ok 20 - use Thread::Queue;
ok 21 - use Thread::Semaphore;
ok 22 - require ExtUtils::MakeMaker;
ok 23 - ExtUtils::MakeMaker->can('prompt')
# About to run basic unit tests.
# Note: These tests *expect* VMware Server or VMware GSX to be installed and running on this system beforehand.
# Do you want to run basic tests? [yes] 
ok 24 - require Log::Log4perl;
ok 25 - require HoneyClient::Util::Config;
ok 26 - HoneyClient::Util::Config->can('getVar')
ok 27 - require HoneyClient::Manager::VM;
ok 28 - HoneyClient::Manager::VM->can('init')
ok 29 - HoneyClient::Manager::VM->can('destroy')
ok 30 - require HoneyClient::Util::SOAP;
ok 31 - HoneyClient::Util::SOAP->can('getServerHandle')
ok 32 - HoneyClient::Util::SOAP->can('getClientHandle')
ok 33 - require File::Basename;
ok 34 - File::Basename->can('dirname')
ok 35 - File::Basename->can('basename')
ok 36 - require File::Copy::Recursive;
ok 37 - File::Copy::Recursive->can('dircopy')
ok 38 - File::Copy::Recursive->can('pathrmdir')
ok 39 - require Data::Dumper;
ok 40 - require File::stat;
ok 41 - require Digest::MD5;
ok 42 - Digest::MD5->can('md5_hex')
ok 43 - require DateTime::HiRes;
ok 44 - require Fcntl;
ok 45 - require VMware::VmPerl;
ok 46 - require VMware::VmPerl::Server;
ok 47 - require VMware::VmPerl::ConnectParams;
ok 48 - require VMware::VmPerl::VM;
ok 49 - require VMware::VmPerl::Question;
ok 50 - require threads;
ok 51 - require threads::shared;
ok 52 - require Thread::Queue;
ok 53 - require Thread::Semaphore;
# About to run extended tests.
# Note: These extended tests will take *significant* time to complete (10-30 minutes).
# Do you want to run extended tests? [no] (Here I put yes)
ok 54 - init()
ok 55 - destroy()
not ok 56 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 256.
ok 57 - enumerate()
not ok 58 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 343.
not ok 59 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 398.
not ok 60 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 444.
not ok 61 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 500.
not ok 62 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 548.
not ok 63 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 617.
not ok 64 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 660.
not ok 65 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 712.
not ok 66 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 757.
not ok 67 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 808.
not ok 68 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 854.
not ok 69 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 897.
not ok 70 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 967.
not ok 71 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 1038.
not ok 72 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 1122.
not ok 73 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 1217.
not ok 74 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 1329.
not ok 75 - HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# 
#   Failed test 'HoneyClient::Util::SOAP->handleFault(): Error occurred during processing.
# HoneyClient::Manager::VM->_connectVM(): Could not connect to VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
# HoneyClient::Manager::VM->_connectVM(): {'err' => bless( {'errNo' => '0','errStr' => 'Success'}, 'err' )}
# '
#   at t/honeyclient_manager_vm.t line 1440.
1..75
# Looks like you failed 19 tests of 75.

Attachments

Change History

09/14/07 09:42:24 changed by kindlund

  • keywords set to vmware, server, delay, make, test, error, centos.
  • status changed from new to assigned.
  • summary changed from When trying to run make test for HC::Manager, tests fail. to When trying to run make test for HC::Manager, HC::Manager::VM tests fail..
  • component changed from HoneyClient::Manager to HoneyClient::Manager::VM.
  • milestone set to 0.9.

Hi,

It looks like these errors are specific to the perl code interacting with your instance of VMware Server. That said, I have a couple of questions:

1) What version/build of VMware Server are you running?

2) Is VMware Server running properly? For example, can you start up and properly shut down all active VMs registered on your system? If you don't have any created, please create a test VM and verify VMware Server is operating properly for you.

Or, we provided a test VM you can use, if you prefer. In your case, it is located at: /home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx

Try loading up the VMware Console, manually registering this VM, and powering it on. The test VM won't contain any OS, but you should see the BIOS load at least to where you get "Operating System not found."

3) Were there any other VMs running on the host system at the time when you performed these tests? The 'make test' call to HC::Manager::VM expects no other VMs to be running, since some of the tests are time-specific. If VMware Server is running (for example) 3 other VMs simultaneously, then it will take longer to complete each VM operation programmatically.

Please let me know if any of this was helpful.

Regards,

— Darien

09/14/07 14:37:48 changed by anonymous

Thank you for your response.

1.) VMware Server: 1.0.3 build-44356

2.) Well since I ran VMware Server on another install of CentOS 5 I assumed it would still work properly (without patching it with VMware-any-any*), I now see that it wont even run properly 

Unable to change virtual machine power state: Couldn't determine owner of config file /home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx
Check that a line for uid 49068 appears in /etc/passwd.

So I am going to update my kernel and try again, I will get back to you and reconfigure vmware, and see if it will let me run it.

3.) There were no other Virtual Machines on there at the time.

However, I can create and run VMs just fine.

09/14/07 15:03:14 changed by kindlund

  • keywords changed from vmware, server, delay, make, test, error, centos to vmware, server, delay, make, test, error, centos, chown.

No problem.

Okay, that version of VMware Server should work.

Actually, that error message you described doesn't mean VMware Server is broken, per se.

Specifically, it looks like you just need to do a "chown" on all the files in the archive that you extracted. See, this error message: 

Unable to change virtual machine power state: Couldn't determine owner of config file /home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx
Check that a line for uid 49068 appears in /etc/passwd.

… this message means that VMware Server can't determine the owner of the .vmx file. If you were to do an "ls -alF" in that directory, you would probably see a bunch of numbers representing the user:group for each file.

In your case, let's say you had a user named "neo" and the group "users". You could fix the aforementioned problem, by issuing the following command: 

chown -R neo:users /home/neo/FIRM/HoneyClient-Manager-0.99

Try this command first. If it still doesn't work, then you can try to reconfigure VMware Server and/or your kernel.

Regards,

— Darien

09/14/07 17:01:20 changed by mbridges

Ah, thanks.

This is the output after I chown the folder 

[root@localhost HoneyClient-Manager-0.99]# perl Makefile.PL
*** Module::AutoInstall version 1.02
*** Checking for Perl dependencies...
[Core Features]
- Carp                          ...loaded. (1.04)
- Config                        ...loaded. (0)
- Config::General               ...loaded. (2.33)
- Data::Dumper                  ...loaded. (2.121_08)
- DateTime::HiRes               ...loaded. (0.01)
- Digest::MD5                   ...loaded. (2.36)
- English                       ...loaded. (1.02)
- ExtUtils::MakeMaker           ...loaded. (6.36)
- Fcntl                         ...loaded. (1.05)
- File::Basename                ...loaded. (2.74)
- File::Copy                    ...loaded. (2.09)
- File::Copy::Recursive         ...loaded. (0.35)
- File::stat                    ...loaded. (1.00)
- FileHandle                    ...loaded. (2.01)
- HoneyClient::Util::Config     ...loaded. (0.98)
- HoneyClient::Util::SOAP       ...loaded. (0.98)
- IO::File                      ...loaded. (1.13)
- IPTables::IPv4                ...loaded. (0.98)
- Log::Log4perl                 ...loaded. (1.12)
- MIME::Base64                  ...loaded. (3.07)
- Net::DNS::Resolver            ...loaded. (614)
- POSIX                         ...loaded. (1.09)
- Proc::ProcessTable            ...loaded. (0.41)
- Storable                      ...loaded. (2.15)
- Thread::Queue                 ...loaded. (2.00)
- Thread::Semaphore             ...loaded. (2.01)
- Tie::File                     ...loaded. (0.97)
- Time::HiRes                   ...loaded. (1.86)
- VMware::VmPerl                ...loaded. (1.01)
- VMware::VmPerl::ConnectParams ...loaded. (1.01)
- VMware::VmPerl::Question      ...loaded. (1.01)
- VMware::VmPerl::Server        ...loaded. (1.01)
- VMware::VmPerl::VM            ...loaded. (1.01)
- sigtrap                       ...loaded. (1.02)
Warning, threads::shared has already been loaded.  To
enable shared variables, 'use threads' must be called
before threads::shared or any module that uses it.
- threads                       ...loaded. (1.65)
- threads::shared               ...loaded. (1.13)
*** Module::AutoInstall configuration finished.
Writing Makefile for HoneyClient::Manager
[root@localhost HoneyClient-Manager-0.99]# make
Manifying blib/man3/HoneyClient::Manager::VM::Clone.3pm
Manifying blib/man3/HoneyClient::Manager::VM.3pm
Manifying blib/man3/HoneyClient::Manager::FW.3pm
Manifying blib/man3/HoneyClient::Manager.3pm
[root@localhost HoneyClient-Manager-0.99]# make test
PERL_DL_NONLAZY=1 /usr/bin/perl "-MExtUtils::Command::MM" "-e" "test_harness(0, 'inc', 'blib/lib', 'blib/arch')" t/honeyclient_manager_vm.t
t/honeyclient_manager_vm....ok 1/0# About to run basic unit tests.           
# Note: These tests *expect* VMware Server or VMware GSX to be installed and running on this system beforehand.

t/honeyclient_manager_vm....ok 24/0Confused test output: test 25 answered after test 25
Confused test output: test 26 answered after test 26
Confused test output: test 27 answered after test 27
Confused test output: test 28 answered after test 28
Confused test output: test 29 answered after test 29
Confused test output: test 30 answered after test 30
Confused test output: test 31 answered after test 31
Confused test output: test 32 answered after test 32
Confused test output: test 33 answered after test 33
Confused test output: test 34 answered after test 34
Confused test output: test 35 answered after test 35
Confused test output: test 36 answered after test 36
Confused test output: test 37 answered after test 37
Confused test output: test 38 answered after test 38
Confused test output: test 39 answered after test 39
Confused test output: test 40 answered after test 40
Confused test output: test 41 answered after test 41
Confused test output: test 42 answered after test 42
Confused test output: test 43 answered after test 43
Confused test output: test 44 answered after test 44
Confused test output: test 45 answered after test 45
Confused test output: test 46 answered after test 46
Confused test output: test 47 answered after test 47
Confused test output: test 48 answered after test 48
Confused test output: test 49 answered after test 49
Confused test output: test 50 answered after test 50
Confused test output: test 51 answered after test 51
Confused test output: test 52 answered after test 52
# About to run extended tests.
# Note: These extended tests will take *significant* time to complete (10-30 minutes).

Don't know which tests failed: got 52 ok, expected 0
FAILED--1 test script could be run, alas--no output ever seen
make: *** [test_dynamic] Error 255
[root@localhost HoneyClient-Manager-0.99]# perl -Ilib/ t/honeyclient_manager_vm.t
ok 1 - use ExtUtils::MakeMaker;
ok 2 - use Log::Log4perl;
ok 3 - use HoneyClient::Util::Config;
ok 4 - use HoneyClient::Manager::VM;
ok 5 - use HoneyClient::Util::SOAP;
ok 6 - use File::Basename;
ok 7 - use File::Copy::Recursive;
ok 8 - use Data::Dumper;
ok 9 - use File::stat;
ok 10 - use Digest::MD5;
ok 11 - use DateTime::HiRes;
ok 12 - use Fcntl;
ok 13 - use VMware::VmPerl;
ok 14 - use VMware::VmPerl::Server;
ok 15 - use VMware::VmPerl::ConnectParams;
ok 16 - use VMware::VmPerl::VM;
ok 17 - use VMware::VmPerl::Question;
ok 18 - use threads;
ok 19 - use threads::shared;
ok 20 - use Thread::Queue;
ok 21 - use Thread::Semaphore;
ok 22 - require ExtUtils::MakeMaker;
ok 23 - ExtUtils::MakeMaker->can('prompt')
# About to run basic unit tests.
# Note: These tests *expect* VMware Server or VMware GSX to be installed and running on this system beforehand.
# Do you want to run basic tests? [yes] 
ok 24 - require Log::Log4perl;
ok 25 - require HoneyClient::Util::Config;
ok 26 - HoneyClient::Util::Config->can('getVar')
ok 27 - require HoneyClient::Manager::VM;
ok 28 - HoneyClient::Manager::VM->can('init')
ok 29 - HoneyClient::Manager::VM->can('destroy')
ok 30 - require HoneyClient::Util::SOAP;
ok 31 - HoneyClient::Util::SOAP->can('getServerHandle')
ok 32 - HoneyClient::Util::SOAP->can('getClientHandle')
ok 33 - require File::Basename;
ok 34 - File::Basename->can('dirname')
ok 35 - File::Basename->can('basename')
ok 36 - require File::Copy::Recursive;
ok 37 - File::Copy::Recursive->can('dircopy')
ok 38 - File::Copy::Recursive->can('pathrmdir')
ok 39 - require Data::Dumper;
ok 40 - require File::stat;
ok 41 - require Digest::MD5;
ok 42 - Digest::MD5->can('md5_hex')
ok 43 - require DateTime::HiRes;
ok 44 - require Fcntl;
ok 45 - require VMware::VmPerl;
ok 46 - require VMware::VmPerl::Server;
ok 47 - require VMware::VmPerl::ConnectParams;
ok 48 - require VMware::VmPerl::VM;
ok 49 - require VMware::VmPerl::Question;
ok 50 - require threads;
ok 51 - require threads::shared;
ok 52 - require Thread::Queue;
ok 53 - require Thread::Semaphore;
# About to run extended tests.
# Note: These extended tests will take *significant* time to complete (10-30 minutes).
# Do you want to run extended tests? [no] yes
ok 54 - init()
ok 55 - destroy()
ok 56 - isRegisteredVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 57 - isRegisteredVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 58 - enumerate()
ok 59 - getStateVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 60 - startVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 61 - startVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 62 - stopVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 63 - stopVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 64 - rebootVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 65 - rebootVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 66 - suspendVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 67 - suspendVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 68 - fullCloneVM(src_config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx', dest_dir => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone')
ok 69 - fullCloneVM(src_config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx', dest_dir => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone')
Perl exited with active threads:
        0 running and unjoined
        1 finished and unjoined
        0 running and detached
ok 70 - getNameVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 71 - setNameVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx', name => 'newVM')
ok 72 - setNameVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx', name => 'newVM')
ok 73 - getMACaddrVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
Use of uninitialized value in pattern match (m//) at t/honeyclient_manager_vm.t line 795, <STDIN> line 2.
not ok 74 - getIPaddrVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
#   Failed test 'getIPaddrVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')'
#   at t/honeyclient_manager_vm.t line 795.
#                   undef
#     doesn't match '/[0-9]{1,3}.[0-9]{1,3}.[0-9]{1,3}.[0-9]{1,3}/'
# The getIPaddrVM() call failed.  Attempted to retrieve the IP address of test VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).
ok 75 - registerVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 76 - registerVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 77 - unregisterVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 78 - unregisterVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
ok 79 - answerVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx')
ok 80 - destroyVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx')
ok 81 - destroyVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx')
Perl exited with active threads:
        0 running and unjoined
        1 finished and unjoined
        0 running and detached
ok 82 - setMasterVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx')
ok 83 - setMasterVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx')
ok 84 - setMasterVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx')
ok 85 - setMasterVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx')
ok 86 - setMasterVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx')
ok 87 - setMasterVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx')
Perl exited with active threads:
        0 running and unjoined
        1 finished and unjoined
        0 running and detached
ok 88 - quickCloneVM(src_config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_master/winXPPro.vmx', dest_dir => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone')
ok 89 - quickCloneVM(src_config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_master/winXPPro.vmx', dest_dir => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone')
Perl exited with active threads:
        0 running and unjoined
        2 finished and unjoined
        0 running and detached
ok 90 - snapshotVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx', snapshot_file => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone.tar.gz')
ok 91 - snapshotVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx', snapshot_file => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone.tar.gz')
ok 92 - snapshotVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx', snapshot_file => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone.tar.gz')
Perl exited with active threads:
        0 running and unjoined
        3 finished and unjoined
        0 running and detached
ok 93 - revertVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx', snapshot_file => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone.tar.gz')
ok 94 - revertVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone/winXPPro.vmx', snapshot_file => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm_clone.tar.gz')
Perl exited with active threads:
        0 running and unjoined
        3 finished and unjoined
        0 running and detached
1..94
# Looks like you failed 1 test of 94.

Something tells me I set up some network setting wrong. Also will I have to Chown the Firewall VM folder?

Also, whenever I try to make the test I always get confused output and it ceases to run right so I have to break out of it…but when I run 

perl -Ilib/ t/honeyclient_manager_vm.t

the tests are fine.

Thanks

09/14/07 17:56:16 changed by kindlund

  • keywords changed from vmware, server, delay, make, test, error, centos, chown to vmware, server, delay, make, test, error, centos, chown, getIPaddrVM, #81.
  • status changed from assigned to closed.
  • resolution set to duplicate.

Okay, so this error is actually well known. 

Use of uninitialized value in pattern match (m//) at t/honeyclient_manager_vm.t line 795, <STDIN> line 2.
not ok 74 - getIPaddrVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
#   Failed test 'getIPaddrVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')'
#   at t/honeyclient_manager_vm.t line 795.
#                   undef
#     doesn't match '/[0-9]{1,3}.[0-9]{1,3}.[0-9]{1,3}.[0-9]{1,3}/'
# The getIPaddrVM() call failed.  Attempted to retrieve the IP address of test VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).

Please see the first comment on ticket #81, for instructions on how to resolve this issue:

http://www.honeyclient.org/trac/ticket/81#comment:1

In the future, please use our site search feature, as it is possible we may already have closed a ticket regarding these issues. However, if you can't find anything related, feel free to add to this ticket.

Regards,

— Darien

09/14/07 17:58:23 changed by kindlund

Also, you can't run "make test" on the HC::Manager code.

You have to run: 

PERL_MM_USE_DEFAULT=1 make test

Regards,

— Darien

09/15/07 01:28:53 changed by mbridges

I did what comment 1 said to do and checked my VMware network settings, and /etc/vmware/vmnet1/dhcpd/dhcpd.conf and I am still failing test 74. I can paste the last lines of /var/log/messages. 

Use of uninitialized value in pattern match (m//) at t/honeyclient_manager_vm.t line 795, <STDIN> line 2.
not ok 74 - getIPaddrVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')
#   Failed test 'getIPaddrVM(config => '/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx')'
#   at t/honeyclient_manager_vm.t line 795.
#                   undef
#     doesn't match '/[0-9]{1,3}.[0-9]{1,3}.[0-9]{1,3}.[0-9]{1,3}/'
# The getIPaddrVM() call failed.  Attempted to retrieve the IP address of test VM (/home/neo/FIRM/HoneyClient-Manager-0.99/t/test_vm/winXPPro.vmx).

/var/log/messages 

Sep 14 23:59:46 localhost syslogd 1.4.1: restart (remote reception).
Sep 14 23:59:46 localhost kernel: klogd 1.4.1, log source = /proc/kmsg started.
Sep 15 00:00:56 localhost kernel: /dev/vmnet: open called by PID 23264 (vmware-vmx)
Sep 15 00:00:56 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:01:01 localhost crond[23276]: (root) CMD (run-parts /etc/cron.hourly)
Sep 15 00:01:03 localhost kernel: vmmon: Had to deallocate locked 1275 pages from vm driver ee8ef000
Sep 15 00:01:03 localhost kernel: vmmon: Had to deallocate AWE 2328 pages from vm driver ee8ef000
Sep 15 00:01:23 localhost kernel: /dev/vmnet: open called by PID 23292 (vmware-vmx)
Sep 15 00:01:23 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:01:30 localhost kernel: vmmon: Had to deallocate locked 1275 pages from vm driver d77ec000
Sep 15 00:01:30 localhost kernel: vmmon: Had to deallocate AWE 2328 pages from vm driver d77ec000
Sep 15 00:01:52 localhost kernel: /dev/vmnet: open called by PID 23326 (vmware-vmx)
Sep 15 00:01:52 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:01:59 localhost kernel: vmmon: Had to deallocate locked 1275 pages from vm driver e9a75000
Sep 15 00:01:59 localhost kernel: vmmon: Had to deallocate AWE 2328 pages from vm driver e9a75000
Sep 15 00:01:59 localhost kernel: /dev/vmnet: open called by PID 23326 (vmware-vmx)
Sep 15 00:01:59 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:02:06 localhost kernel: vmmon: Had to deallocate locked 1275 pages from vm driver f0b79000
Sep 15 00:02:06 localhost kernel: vmmon: Had to deallocate AWE 2326 pages from vm driver f0b79000
Sep 15 00:02:26 localhost kernel: /dev/vmnet: open called by PID 23363 (vmware-vmx)
Sep 15 00:02:26 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:02:34 localhost kernel: vmmon: Had to deallocate locked 1275 pages from vm driver e9a75000
Sep 15 00:02:34 localhost kernel: vmmon: Had to deallocate AWE 2326 pages from vm driver e9a75000
Sep 15 00:02:42 localhost kernel: /dev/vmnet: open called by PID 23385 (vmware-vmx)
Sep 15 00:02:42 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:02:49 localhost kernel: vmmon: Had to deallocate locked 41 pages from vm driver d78d3000
Sep 15 00:02:49 localhost kernel: vmmon: Had to deallocate AWE 2036 pages from vm driver d78d3000
Sep 15 00:03:31 localhost kernel: /dev/vmmon[23182]: host clock rate change request 19 -> 0
Sep 15 00:03:31 localhost kernel: vmmon: Had to deallocate locked 934 pages from vm driver ee9ee000
Sep 15 00:03:31 localhost kernel: vmmon: Had to deallocate AWE 2475 pages from vm driver ee9ee000
Sep 15 00:04:53 localhost kernel: /dev/vmnet: open called by PID 23516 (vmware-vmx)
Sep 15 00:04:53 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:04:53 localhost kernel: /dev/vmmon[23524]: host clock rate change request 0 -> 19
Sep 15 00:05:13 localhost kernel: /dev/vmmon[23516]: host clock rate change request 19 -> 0
Sep 15 00:05:13 localhost kernel: vmmon: Had to deallocate locked 1251 pages from vm driver e4b29000
Sep 15 00:05:13 localhost kernel: vmmon: Had to deallocate AWE 2471 pages from vm driver e4b29000
Sep 15 00:06:25 localhost kernel: /dev/vmnet: open called by PID 23590 (vmware-vmx)
Sep 15 00:06:25 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:06:25 localhost kernel: /dev/vmmon[23600]: host clock rate change request 0 -> 19
Sep 15 00:06:28 localhost kernel: /dev/vmmon[23590]: host clock rate change request 19 -> 0
Sep 15 00:06:28 localhost kernel: vmmon: Had to deallocate locked 1279 pages from vm driver db916000
Sep 15 00:06:28 localhost kernel: vmmon: Had to deallocate AWE 2216 pages from vm driver db916000
Sep 15 00:07:02 localhost kernel: /dev/vmnet: open called by PID 23636 (vmware-vmx)
Sep 15 00:07:02 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:07:02 localhost kernel: /dev/vmmon[23646]: host clock rate change request 0 -> 19
Sep 15 00:07:09 localhost kernel: /dev/vmmon[23636]: host clock rate change request 19 -> 0
Sep 15 00:07:09 localhost kernel: vmmon: Had to deallocate locked 1276 pages from vm driver e4b1d000
Sep 15 00:07:09 localhost kernel: vmmon: Had to deallocate AWE 2328 pages from vm driver e4b1d000
Sep 15 00:07:56 localhost kernel: /dev/vmnet: open called by PID 23693 (vmware-vmx)
Sep 15 00:07:56 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:07:56 localhost kernel: /dev/vmmon[23703]: host clock rate change request 0 -> 19
Sep 15 00:08:05 localhost kernel: /dev/vmmon[23693]: host clock rate change request 19 -> 0
Sep 15 00:08:05 localhost kernel: vmmon: Had to deallocate locked 1276 pages from vm driver e3629000
Sep 15 00:08:05 localhost kernel: vmmon: Had to deallocate AWE 2328 pages from vm driver e3629000
Sep 15 00:09:04 localhost kernel: /dev/vmnet: open called by PID 23762 (vmware-vmx)
Sep 15 00:09:04 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:09:04 localhost kernel: /dev/vmmon[23772]: host clock rate change request 0 -> 19
Sep 15 00:09:57 localhost kernel: /dev/vmmon[23762]: host clock rate change request 19 -> 0
Sep 15 00:09:57 localhost kernel: vmmon: Had to deallocate locked 1210 pages from vm driver e6b71000
Sep 15 00:09:57 localhost kernel: vmmon: Had to deallocate AWE 2475 pages from vm driver e6b71000
Sep 15 00:10:31 localhost kernel: /dev/vmnet: open called by PID 23812 (vmware-vmx)
Sep 15 00:10:31 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:10:31 localhost kernel: /dev/vmmon[23823]: host clock rate change request 0 -> 19
Sep 15 00:10:35 localhost kernel: /dev/vmmon[23812]: host clock rate change request 19 -> 0
Sep 15 00:10:35 localhost kernel: vmmon: Had to deallocate locked 24 pages from vm driver f15e0000
Sep 15 00:10:35 localhost kernel: vmmon: Had to deallocate AWE 1956 pages from vm driver f15e0000
Sep 15 00:10:35 localhost kernel: /dev/vmnet: open called by PID 23812 (vmware-vmx)
Sep 15 00:10:35 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:10:35 localhost kernel: /dev/vmmon[23833]: host clock rate change request 0 -> 19
Sep 15 00:11:22 localhost kernel: /dev/vmmon[23812]: host clock rate change request 19 -> 0
Sep 15 00:11:22 localhost kernel: vmmon: Had to deallocate locked 1223 pages from vm driver f15e0000
Sep 15 00:11:22 localhost kernel: vmmon: Had to deallocate AWE 2475 pages from vm driver f15e0000
Sep 15 00:12:21 localhost kernel: /dev/vmnet: open called by PID 23894 (vmware-vmx)
Sep 15 00:12:21 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:12:21 localhost kernel: /dev/vmmon[23904]: host clock rate change request 0 -> 19
Sep 15 00:12:45 localhost kernel: /dev/vmmon[23894]: host clock rate change request 19 -> 0
Sep 15 00:12:45 localhost kernel: vmmon: Had to deallocate locked 1249 pages from vm driver e802a000
Sep 15 00:12:45 localhost kernel: vmmon: Had to deallocate AWE 2471 pages from vm driver e802a000
Sep 15 00:13:16 localhost kernel: /dev/vmnet: open called by PID 23921 (vmware-vmx)
Sep 15 00:13:16 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:13:16 localhost kernel: /dev/vmmon[23932]: host clock rate change request 0 -> 19
Sep 15 00:13:33 localhost kernel: /dev/vmmon[23921]: host clock rate change request 19 -> 0
Sep 15 00:13:33 localhost kernel: vmmon: Had to deallocate locked 51 pages from vm driver dc370000
Sep 15 00:13:33 localhost kernel: vmmon: Had to deallocate AWE 2182 pages from vm driver dc370000
Sep 15 00:13:55 localhost kernel: /dev/vmnet: open called by PID 23947 (vmware-vmx)
Sep 15 00:13:55 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:13:55 localhost kernel: /dev/vmmon[23958]: host clock rate change request 0 -> 19
Sep 15 00:15:36 localhost kernel: /dev/vmmon[23947]: host clock rate change request 19 -> 0
Sep 15 00:15:36 localhost kernel: vmmon: Had to deallocate locked 51 pages from vm driver e058f000
Sep 15 00:15:36 localhost kernel: vmmon: Had to deallocate AWE 2182 pages from vm driver e058f000
Sep 15 00:16:23 localhost kernel: /dev/vmnet: open called by PID 24010 (vmware-vmx)
Sep 15 00:16:23 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:16:23 localhost kernel: /dev/vmmon[24020]: host clock rate change request 0 -> 19
Sep 15 00:16:47 localhost kernel: /dev/vmmon[24010]: host clock rate change request 19 -> 0
Sep 15 00:16:47 localhost kernel: vmmon: Had to deallocate locked 1249 pages from vm driver ceb4f000
Sep 15 00:16:47 localhost kernel: vmmon: Had to deallocate AWE 2471 pages from vm driver ceb4f000
Sep 15 00:17:16 localhost kernel: /dev/vmnet: open called by PID 24035 (vmware-vmx)
Sep 15 00:17:16 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:17:16 localhost kernel: /dev/vmmon[24046]: host clock rate change request 0 -> 19
Sep 15 00:17:48 localhost kernel: /dev/vmmon[24035]: host clock rate change request 19 -> 0
Sep 15 00:17:48 localhost kernel: vmmon: Had to deallocate locked 51 pages from vm driver f066f000
Sep 15 00:17:48 localhost kernel: vmmon: Had to deallocate AWE 2182 pages from vm driver f066f000
Sep 15 00:18:09 localhost kernel: /dev/vmnet: open called by PID 24064 (vmware-vmx)
Sep 15 00:18:09 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 00:18:09 localhost kernel: /dev/vmmon[24075]: host clock rate change request 0 -> 19
Sep 15 00:19:52 localhost kernel: /dev/vmmon[24064]: host clock rate change request 19 -> 0
Sep 15 00:19:52 localhost kernel: vmmon: Had to deallocate locked 51 pages from vm driver de1fe000
Sep 15 00:19:52 localhost kernel: vmmon: Had to deallocate AWE 2182 pages from vm driver de1fe000
Sep 15 00:23:36 localhost gconfd (root-24131): starting (version 2.14.0), pid 24131 user 'root'
Sep 15 00:23:36 localhost gconfd (root-24131): Resolved address "xml:readonly:/etc/gconf/gconf.xml.mandatory" to a read-only configuration source at position 0
Sep 15 00:23:36 localhost gconfd (root-24131): Resolved address "xml:readwrite:/root/.gconf" to a writable configuration source at position 1
Sep 15 00:23:36 localhost gconfd (root-24131): Resolved address "xml:readonly:/etc/gconf/gconf.xml.defaults" to a read-only configuration source at position 2

Thanks.

09/15/07 01:29:02 changed by anonymous

  • status changed from closed to reopened.
  • resolution deleted.

09/15/07 14:13:49 changed by kindlund

  • type changed from bug to issue.

Okay, so here's the problem.

The HC::Manager::VM code is trying to figure out the IP address of a VM when it powers on. It does this check by scanning the /var/log/messages file. In order for the perl code to read this file, /var/log/messages must be chmod 0644.

When you power on a VM that tries to obtain a DHCP lease on the network, you should see the following entries in your log file: 

Aug 30 15:10:53 honeyclient3 vmnet-dhcpd: DHCPDISCOVER from 00:0c:29:5e:08:b1 via vmnet1
Aug 30 15:10:54 honeyclient3 vmnet-dhcpd: DHCPOFFER on 10.0.0.202 to 00:0c:29:5e:08:b1 via vmnet1
Aug 30 15:10:54 honeyclient3 vmnet-dhcpd: DHCPREQUEST for 10.0.0.202 from 00:0c:29:5e:08:b1 via vmnet1
Aug 30 15:10:54 honeyclient3 vmnet-dhcpd: DHCPACK on 10.0.0.202 to 00:0c:29:5e:08:b1 via vmnet1

If you're not seeing these entries in your logfile, then there are 2 possible issues:

1) Do a "ps ax | grep dhcpd" and see if the vmnet-dhcpd daemons are properly running on the host system. You can also make sure these are working properly by checking to see that the powered on VM has a valid IP address when it does a DHCP request.

2) Check your /etc/syslog.conf file and make sure these DHCP messages are not filtered out. It's possible that the DHCP messages may require logging at the debug level, in order for this information to be written to the syslog file.

Let me know if either (or both) of these suggestions work.

Regards,

— Darien

09/15/07 14:59:58 changed by mbridges

Okay so the dhcp services for vmware are running 

[root@localhost neo]# ps ax | grep dhcpd
 2968 ?        Ss     0:00 /usr/bin/vmnet-dhcpd -cf /etc/vmware/vmnet8/dhcpd/dhcpd.conf -lf /etc/vmware/vmnet8/dhcpd/dhcpd.leases -pf /var/run/vmnet-dhcpd-vmnet8.pid vmnet8
17301 pts/1    S+     0:00 grep dhcpd

And I do not think dhcp messages are being filtered out. 

# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.*							/dev/console

# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none;*.*		/var/log/messages

# The authpriv file has restricted access.
authpriv.*						/var/log/secure

# Log all the mail messages in one place.
mail.*							-/var/log/maillog


# Log cron stuff
cron.*							/var/log/cron

# Everybody gets emergency messages
*.emerg							*

# Save news errors of level crit and higher in a special file.
uucp,news.crit						/var/log/spooler

# Save boot messages also to boot.log
local7.*						/var/log/boot.log

Even if I start independently I can still not get the DHCP messages.

From when I loaded up testVM 

Sep 15 13:55:00 localhost kernel: /dev/vmnet: open called by PID 17363 (vmware-vmx)
Sep 15 13:55:00 localhost kernel: /dev/vmnet: port on hub 1 successfully opened
Sep 15 13:55:00 localhost kernel: /dev/vmmon[17373]: host clock rate change request 0 -> 19

09/15/07 15:43:00 changed by kindlund

Okay, so this test VM has no operating system installed on it. What should happen is the VM tries to eventually do a PXE boot, where the BIOS-loaded PXE boot process attempts to get a DHCP lease from the network.

Load up VMware Console, power on the test VM manually. Do you see the VM attempting a PXE boot process? If not, could you go into the VMware BIOS and change it so that it does? I would be very surprised if this was the case. If so, maybe VMware changed the default BIOS to not PXE boot anymore… not 100% sure.

Regards,

— Darien

09/15/07 17:27:09 changed by mbridges

Yes, it does do a PXE boot.

And it tries to get an IP address but… 

CLIENT MAC ADDR: 00 0C 29 0D 5C 94 GUID: 564D50BE-B977-2756-7747-B38D4E0D5C94
PXE-E51: No DHCP or proxyDHCP offers were received.

09/15/07 22:20:44 changed by kindlund

Okay, I see the problem.

The test VM uses the Host-Only network (vmnet1). By default, there should be an instance of vmnet-dhcpd running on your host system that handles DHCP queries on vmnet1.

So, in your case, when you did a "ps ax | grep dhcp", you only had this showing: 

2968 ?        Ss     0:00 /usr/bin/vmnet-dhcpd -cf /etc/vmware/vmnet8/dhcpd/dhcpd.conf -lf /etc/vmware/vmnet8/dhcpd/dhcpd.leases -pf /var/run/vmnet-dhcpd-vmnet8.pid vmnet8

The problem is, you need 2 separate vmnet-dhcpd instances running on both vmnet1 and vmnet8 interfaces, like this: 

14525 ?        Ss     0:00 /usr/bin/vmnet-dhcpd -cf /etc/vmware/vmnet8/dhcpd/dhcpd.conf -lf /etc/vmware/vmnet8/dhcpd/dhcpd.leases -pf /var/run/vmnet-dhcpd-vmnet8.pid vmnet8
14533 ?        Ss     0:00 /usr/bin/vmnet-dhcpd -cf /etc/vmware/vmnet1/dhcpd/dhcpd.conf -lf /etc/vmware/vmnet1/dhcpd/dhcpd.leases -pf /var/run/vmnet-dhcpd-vmnet1.pid vmnet1

See how the second instance is specifc to vmnet1? If you've configured your VMware Server's networking properly, as stated in the UserGuide, you should be able to restart the main vmware service (i.e., "sudo /etc/init.d/vmware restart") and that should start up the vmnet-dhcpd service for vmnet1.

Hope this helps,

— Darien

09/16/07 02:37:31 changed by mbridges

  • status changed from reopened to closed.
  • resolution set to fixed.

After reconfiguring vmware and running the tests over and over again…74 finally passed.

The logs are populated with vmware-dhcp messages and dhcp is running for vmnet1.

Thank you for all of your help. If I have another issue I will just make another ticket.

-Michael

09/16/07 10:24:43 changed by kindlund

No problem. Glad to have helped.

— Darien

Add/Change #96 (When trying to run make test for HC::Manager, HC::Manager::VM tests fail.)




Change Properties
Action