dkindlund / honeyclient

MITRE HoneyClient Project
http://www.honeyclient.org
GNU General Public License v2.0
8 stars 4 forks source link

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

Closed dkindlund closed 14 years ago

dkindlund commented 14 years ago

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]

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.

}}}

dkindlund commented 14 years ago

Author: kindlund 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

dkindlund commented 14 years ago

Author: 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.

dkindlund commented 14 years ago

Author: kindlund 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

dkindlund commented 14 years ago

Author: 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]

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, 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

dkindlund commented 14 years ago

Author: kindlund Okay, so this error is actually well known.

{{{ Use of uninitialized value in pattern match (m//) at t/honeyclient_manager_vm.t line 795, 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

dkindlund commented 14 years ago

Author: 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

dkindlund commented 14 years ago

Author: 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, 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.

dkindlund commented 14 years ago

Author: anonymous

dkindlund commented 14 years ago

Author: kindlund 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

dkindlund commented 14 years ago

Author: 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 }}}

dkindlund commented 14 years ago

Author: 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

dkindlund commented 14 years ago

Author: 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. }}}

dkindlund commented 14 years ago

Author: 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

dkindlund commented 14 years ago

Author: mbridges 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

dkindlund commented 14 years ago

Author: kindlund No problem. Glad to have helped.

-- Darien