Navigation

← Previous Changeset
Next Changeset →

Changeset 2288

Timestamp:

07/31/09 17:02:38 (1 year ago)

Author:

kindlund

Message:

Updated log format to include PID by default; adjusted VIX usage so that we can reuse handles as much as possible (but with auto-reconnect logic built in). Still need to modify VIX logic so that it can be bypassed for older ESX 3.5U4 deployments.

Files:

honeyclient/trunk/bin/firewall/firewalld (modified) (2 diffs)
honeyclient/trunk/bin/pcap/pcapd (modified) (2 diffs)
honeyclient/trunk/etc/honeyclient.xml (modified) (3 diffs)
honeyclient/trunk/etc/honeyclient_log.conf (modified) (2 diffs)
honeyclient/trunk/lib/HoneyClient/Manager.pm (modified) (6 diffs)
honeyclient/trunk/lib/HoneyClient/Manager/ESX/Clone.pm (modified) (60 diffs)
honeyclient/trunk/lib/HoneyClient/Manager/Firewall/Client.pm (modified) (2 diffs)
honeyclient/trunk/lib/HoneyClient/Manager/Firewall/Server.pm (modified) (3 diffs)
honeyclient/trunk/lib/HoneyClient/Manager/Pcap/Client.pm (modified) (2 diffs)
honeyclient/trunk/lib/HoneyClient/Manager/Pcap/Server.pm (modified) (3 diffs)
honeyclient/trunk/lib/HoneyClient/Manager/Worker.pm (modified) (13 diffs)
honeyclient/trunk/lib/HoneyClient/Util/EventEmitter.pm (modified) (1 diff)

Legend:

: Unmodified
: Added
: Removed
: Modified
: Copied
: Moved

honeyclient/trunk/bin/firewall/firewalld

r2006	r2288
28	28	# Create a shutdown handler.
29	29	sub shutdown {
30		$LOG->info("Stopping HoneyClient Firewall Daemon ~~[PID: " . $$ . "]~~");
	30	$LOG->info("Stopping HoneyClient Firewall Daemon");
31	31	exit;
32	32	}
…	…
36	36	$SIG{TERM} = \&shutdown;
37	37
38		$LOG->info("Starting HoneyClient Firewall Daemon ~~[PID: " . $$ . "]~~");
	38	$LOG->info("Starting HoneyClient Firewall Daemon");
39	39	HoneyClient::Manager::Firewall::Server->run();

honeyclient/trunk/bin/pcap/pcapd

r2179	r2288
35	35	sub shutdown {
36	36	HoneyClient::Manager::Pcap::Server->stop();
37		$LOG->info("Stopping HoneyClient Pcap Daemon ~~[PID: " . $$ . "]~~");
	37	$LOG->info("Stopping HoneyClient Pcap Daemon");
38	38	exit;
39	39	}
…	…
43	43	$SIG{TERM} = \&shutdown;
44	44
45		$LOG->info("Starting HoneyClient Pcap Daemon ~~[PID: " . $$ . "]~~");
	45	$LOG->info("Starting HoneyClient Pcap Daemon");
46	46	HoneyClient::Manager::Pcap::Server->run();

honeyclient/trunk/etc/honeyclient.xml

r2284	r2288
241	241	</exchange_name>
242	242	<queue_name description="The name of the STOMP queue used to receive messages sent to this component." default="manager.workers">
243		1.manager.workers
	243	500.manager.workers
244	244	</queue_name>
245	245	<routing_key description="The routing key used on all STOMP messages sent to this component." default="pending.job">
246		1.job.create.#
	246	500.job.create.#
247	247	</routing_key>
248	248	</Worker>
…	…
345	345	100
346	346	</max_retry_count>
	347	<vix_enable description="When set to 1, this setting allows the code to use VIX in order to drive the application." default="1">
	348	1
	349	</vix_enable>
347	350	<vix_timeout description="The amount of time (in seconds) that we will wait for a VIX response from the VMware ESX Server, before timing out. Note: This value must be greater than HoneyClient::Agent::timeout." default="300">
348	351	300
…	…
417	420	</low_priority>
418	421	<default_priority description="The default priority to use, when sending messages." default="1">
419		1
	422	500
420	423	</default_priority>
421	424	</EventEmitter>

honeyclient/trunk/etc/honeyclient_log.conf

r1008	r2288
74	74	log4perl.appender.Screen.Threshold=DEBUG
75	75	log4perl.appender.Screen.layout=Log::Log4perl::Layout::PatternLayout
76		log4perl.appender.Screen.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %5p [%M] (%F:%L) - %m%n
	76	log4perl.appender.Screen.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %5p [%M] (%F:%L) - [PID: %P] - %m%n
77	77
78	78	# Syslog Logging Settings
…	…
81	81	log4perl.appender.Syslog.Threshold=DEBUG
82	82	log4perl.appender.Syslog.layout=Log::Log4perl::Layout::PatternLayout
83		log4perl.appender.Syslog.layout.ConversionPattern=%5p [%M] (%F:%L) - %m%n
	83	log4perl.appender.Syslog.layout.ConversionPattern=%5p [%M] (%F:%L) - [PID: %P] - %m%n

honeyclient/trunk/lib/HoneyClient/Manager.pm

r2200	r2288
382	382	sub _shutdown {
383	383	my $LOG = get_logger();
384		$LOG->warn("~~Process ID (" . $$ . "):~~ Received termination signal. Shutting down manager (please wait).");
	384	$LOG->warn("Received termination signal. Shutting down manager (please wait).");
385	385	exit;
386	386	};
…	…
437	437	my ($class, %args) = @_;
438	438
439		$LOG->info("~~Process ID (" . $$ . "):~~ Starting manager.");
	439	$LOG->info("Starting manager.");
440	440
441	441	# Sanity check.
442	442	if (!getVar(name => "enable",
443	443	namespace => "HoneyClient::Manager::Database")) {
444		$LOG->info("~~Process ID (" . $$ . "):~~ Unable to run without database support. Shutting down manager.");
	444	$LOG->info("Unable to run without database support. Shutting down manager.");
445	445	}
446	446
…	…
503	503	while (1) {
504	504
505		$LOG->info("~~Process ID (" . $$ . "):~~ Waiting for new URLs from database.");
	505	$LOG->info("Waiting for new URLs from database.");
506	506
507	507	while (!scalar(%{$queue_url_list})) {
…	…
517	517	}
518	518	}
519		$LOG->info("~~Process ID (" . $$ . "):~~ Received new work and updating the workers.");
	519	$LOG->info("Received new work and updating the workers.");
520	520
521	521	# Collect the list of URLs.
…	…
536	536	});
537	537
538		$LOG->info("~~Process ID (" . $$ . "):~~ Constructing job.");
	538	$LOG->info("Constructing job.");
539	539	# TODO: Delete this, eventually.
540	540	$Data::Dumper::Terse = 0;
…	…
564	564	# Report when a fault occurs.
565	565	if ($@) {
566		$LOG->error("~~Process ID (" . $$ . "):~~ Encountered an error. Shutting down manager. " . $@);
	566	$LOG->error("Encountered an error. Shutting down manager. " . $@);
567	567	}
568	568

honeyclient/trunk/lib/HoneyClient/Manager/ESX/Clone.pm

r2285	r2288
369	369	require Image::Match;
370	370
	371	# Make sure DateTime::HiRes loads.
	372	BEGIN { use_ok('DateTime::HiRes') or diag("Can't load DateTime::HiRes package. Check to make sure the package library is correctly listed within the path."); }
	373	require_ok('DateTime::HiRes');
	374	use DateTime::HiRes;
	375
	376	# Make sure DateTime::Duration loads.
	377	BEGIN { use_ok('DateTime::Duration') or diag("Can't load DateTime::Duration package. Check to make sure the package library is correctly listed within the path."); }
	378	require_ok('DateTime::Duration');
	379	use DateTime::Duration;
	380
371	381	=end testing
372	382
…	…
439	449	use lib qw(blib/lib blib/arch/auto/HoneyClient/Message);
440	450	use HoneyClient::Message;
	451
	452	# Include ISO8601 Date/Time Libraries
	453	use DateTime::HiRes;
	454	use DateTime::Duration;
441	455
442	456	=pod
…	…
630	644
631	645	if ($@) {
632		$LOG->error("~~Process ID (" . $$ . "):~~ Encountered an error. " . $@);
	646	$LOG->error("Encountered an error. " . $@);
633	647	}
634	648
635	649	# Get the object.
636	650	my $self = shift;
	651
	652	# Disconnect from VM via VIX, if enabled.
	653	if (getVar(name => "vix_enable")) {
	654	eval {
	655	$self->_vixDisconnectVM();
	656	};
	657	if ($@) {
	658	$LOG->error("Unable to disconnect from VM. " . $@);
	659	}
	660	}
637	661
638	662	if (defined($self->{'quick_clone_vm_name'}) &&
…	…
651	675	};
652	676
653		$LOG->info("~~Process ID (" . $$ . "):~~ Suspending clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	677	$LOG->info("Suspending clone VM (" . $self->{'quick_clone_vm_name'} . ").");
654	678	my $som = undef;
655	679	my $suspended_at = undef;
…	…
660	684
661	685	if (!defined($som)) {
662		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . ").");
	686	$LOG->error("Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . ").");
663	687	$self->_changeStatus(status => "error");
664	688	} else {
…	…
668	692
669	693	# Upon termination, close our session.
670		$LOG->info("~~Process ID (" . $$ . "):~~ Closing ESX session.");
	694	$LOG->info("Closing ESX session.");
671	695	HoneyClient::Manager::ESX->logout(session => $self->{'_vm_session'});
	696
	697
	698	# Disconnect from host via VIX, if enabled.
	699	if (getVar(name => "vix_enable")) {
	700	eval {
	701	$self->_vixDisconnectHost();
	702	};
	703	if ($@) {
	704	$LOG->error("Unable to disconnect from host. " . $@);
	705	}
	706	}
672	707	}
673	708	}
…	…
697	732	if (($errMsg !~ /Connection refused/) &&
698	733	($errMsg !~ /No route to host/)) {
699		$LOG->warn("~~Process ID (" . $$ . "):~~ Error occurred during processing. " . $errMsg);
	734	$LOG->warn("Error occurred during processing. " . $errMsg);
700	735	Carp::carp __PACKAGE__ . "->_handleAgentFault(): Error occurred during processing.\n" . $errMsg;
701	736	}
…	…
747	782	# and initialize it completely.
748	783
749		$LOG->info("~~Process ID (" . $$ . "):~~ Quick cloning master VM (" . $self->{'master_vm_name'} . ").");
	784	$LOG->info("Quick cloning master VM (" . $self->{'master_vm_name'} . ").");
750	785	($self->{'_vm_session'}, $ret) = HoneyClient::Manager::ESX->quickCloneVM(session => $self->{'_vm_session'}, src_name => $self->{'master_vm_name'});
751	786	if (!defined($ret)) {
752		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to quick clone master VM (" . $self->{'master_vm_name'} . ").");
	787	$LOG->error("Unable to quick clone master VM (" . $self->{'master_vm_name'} . ").");
753	788	Carp::croak "Unable to quick clone master VM (" . $self->{'master_vm_name'} . ").";
754	789	}
…	…
759	794
760	795	# Wait until the VM gets registered, before proceeding.
761		$LOG->debug("~~Process ID (" . $$ . "):~~ Checking if clone VM (" . $self->{'quick_clone_vm_name'} . ") is registered.");
	796	$LOG->debug("Checking if clone VM (" . $self->{'quick_clone_vm_name'} . ") is registered.");
762	797	$ret = undef;
763	798	while (!defined($ret) or !$ret) {
…	…
770	805	}
771	806	# Now, get the VM's configuration.
772		$LOG->debug("~~Process ID (" . $$ . "):~~ Retrieving config of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	807	$LOG->debug("Retrieving config of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
773	808	($self->{'_vm_session'}, $self->{'config'}) = HoneyClient::Manager::ESX->getConfigVM(session => $self->{'_vm_session'}, name => $self->{'quick_clone_vm_name'});
774	809	$self->_changeStatus(status => "registered");
775	810
776	811	# Once registered, check if the VM is ON yet.
777		$LOG->debug("~~Process ID (" . $$ . "):~~ Checking if clone VM (" . $self->{'quick_clone_vm_name'} . ") is powered on.");
	812	$LOG->debug("Checking if clone VM (" . $self->{'quick_clone_vm_name'} . ") is powered on.");
778	813	$ret = undef;
779	814	while (!defined($ret) or ($ret ne 'poweredon')) {
…	…
789	824
790	825	# Now, get the VM's MAC/IP address.
791		$LOG->info("~~Process ID (" . $$ . "):~~ Waiting for a valid MAC/IP address of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	826	$LOG->info("Waiting for a valid MAC/IP address of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
792	827	$ret = undef;
793	828	my $logMsgPrinted = 0;
…	…
803	838	(!defined($self->{'ip_address'}) \|\|
804	839	($ip_address ne $self->{'ip_address'}))) {
805		$LOG->info("~~Process ID (" . $$ . "):~~ Clone VM (" . $self->{'quick_clone_vm_name'} . ") has a new IP (" . $ip_address . ") - updating firewall.");
	840	$LOG->info("Clone VM (" . $self->{'quick_clone_vm_name'} . ") has a new IP (" . $ip_address . ") - updating firewall.");
806	841	$self->_denyNetwork();
807	842	$self->{'ip_address'} = $ip_address;
…	…
814	849	next; # skip further processing
815	850	} elsif (!$logMsgPrinted) {
816		$LOG->info("~~Process ID (" . $$ . "):~~ Initialized clone VM (" . $self->{'quick_clone_vm_name'} . ") using IP (" .
	851	$LOG->info("Initialized clone VM (" . $self->{'quick_clone_vm_name'} . ") using IP (" .
817	852	$self->{'ip_address'} . ") and MAC (" . $self->{'mac_address'} . ").");
818	853
819		$LOG->info("~~Process ID (" . $$ . "):~~ Waiting for Agent daemon to initialize inside clone VM.");
	854	$LOG->info("Waiting for Agent daemon to initialize inside clone VM.");
820	855	$logMsgPrinted = 1;
821	856	}
…	…
846	881
847	882	# Generate a new Operational snapshot.
848		$LOG->info("~~Process ID (" . $$ . "):~~ Creating a new operational snapshot of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	883	$LOG->info("Creating a new operational snapshot of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
849	884	($self->{'_vm_session'}, $self->{'name'}) = HoneyClient::Manager::ESX->snapshotVM(session => $self->{'_vm_session'},
850	885	name => $self->{'quick_clone_vm_name'},
851	886	snapshot_description => getVar(name => "operational_quick_clone_snapshot_description"));
852	887	$self->{'_num_snapshots'}++;
853		$LOG->info("~~Process ID (" . $$ . "):~~ Created operational snapshot (" . $self->{'name'} . ") on clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	888	$LOG->info("Created operational snapshot (" . $self->{'name'} . ") on clone VM (" . $self->{'quick_clone_vm_name'} . ").");
854	889
855	890	# XXX: We need to separate this call into 2 smaller ones.
…	…
894	929	# First, make sure that an operational snapshot name was already provided (as a basis).
895	930	if (!defined($self->{'name'})) {
896		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to start clone VM (" . $self->{'quick_clone_vm_name'} . "): No operational snapshot name provided.");
	931	$LOG->error("Unable to start clone VM (" . $self->{'quick_clone_vm_name'} . "): No operational snapshot name provided.");
897	932	Carp::croak "Unable to start clone VM (" . $self->{'quick_clone_vm_name'} . "): No operational snapshot name provided.";
898	933	}
899	934
900	935	# Revert to operational snapshot; upon revert, the VM will already be running.
901		$LOG->info("~~Process ID (" . $$ . "):~~ Reverting clone VM (" . $self->{'quick_clone_vm_name'} . ") to operational snapshot (" . $self->{'name'} . ").");
	936	$LOG->info("Reverting clone VM (" . $self->{'quick_clone_vm_name'} . ") to operational snapshot (" . $self->{'name'} . ").");
902	937	$ret = HoneyClient::Manager::ESX->revertVM(session => $self->{'_vm_session'}, name => $self->{'quick_clone_vm_name'}, snapshot_name => $self->{'name'});
903	938	if (!$ret) {
904		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to start clone VM (" . $self->{'quick_clone_vm_name'} . "): Failed to revert to operational snapshot.");
	939	$LOG->error("Unable to start clone VM (" . $self->{'quick_clone_vm_name'} . "): Failed to revert to operational snapshot.");
905	940	Carp::croak "Unable to start clone VM (" . $self->{'quick_clone_vm_name'} . "): Failed to revert to operational snapshot.";
906	941	}
…	…
913	948	new_snapshot_description => getVar(name => "operational_quick_clone_snapshot_description"));
914	949	if (!defined($self->{'name'})) {
915		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to start clone VM (" . $self->{'quick_clone_vm_name'} . "): Failed to rename operational snapshot.");
	950	$LOG->error("Unable to start clone VM (" . $self->{'quick_clone_vm_name'} . "): Failed to rename operational snapshot.");
916	951	Carp::croak "Unable to start clone VM (" . $self->{'quick_clone_vm_name'} . "): Failed to rename operational snapshot.";
917	952	}
918		$LOG->info("~~Process ID (" . $$ . "):~~ Renamed operational snapshot on clone VM (" . $self->{'quick_clone_vm_name'} . ") to (" . $self->{'name'} . ").");
	953	$LOG->info("Renamed operational snapshot on clone VM (" . $self->{'quick_clone_vm_name'} . ") to (" . $self->{'name'} . ").");
919	954
920	955	# Now, get the VM's configuration.
921		$LOG->debug("~~Process ID (" . $$ . "):~~ Retrieving config of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	956	$LOG->debug("Retrieving config of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
922	957	($self->{'_vm_session'}, $self->{'config'}) = HoneyClient::Manager::ESX->getConfigVM(session => $self->{'_vm_session'}, name => $self->{'quick_clone_vm_name'});
923	958
924		$LOG->info("~~Process ID (" . $$ . "):~~ Starting clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	959	$LOG->info("Starting clone VM (" . $self->{'quick_clone_vm_name'} . ").");
925	960	$self->{'_vm_session'} = HoneyClient::Manager::ESX->startVM(session => $self->{'_vm_session'}, name => $self->{'quick_clone_vm_name'});
926	961	# Sanity check: Make sure the VM is powered ON.
927	962	$ret = undef;
928	963	while (!defined($ret) or ($ret ne 'poweredon')) {
929		$LOG->info("~~Process ID (" . $$ . "):~~ Checking if clone VM (" . $self->{'quick_clone_vm_name'} . ") is powered on.");
	964	$LOG->info("Checking if clone VM (" . $self->{'quick_clone_vm_name'} . ") is powered on.");
930	965	($self->{'_vm_session'}, $ret) = HoneyClient::Manager::ESX->getStateVM(session => $self->{'_vm_session'}, name => $self->{'quick_clone_vm_name'});
931	966
…	…
1062	1097
1063	1098	# Croak if no valid argument is supplied.
1064		$LOG->error("~~Process ID (" . $$ . "):~~ Error: No status argument supplied.");
	1099	$LOG->error("Error: No status argument supplied.");
1065	1100	Carp::croak "Error: No status argument supplied.";
1066	1101	}
…	…
1118	1153	if (length($COMPROMISE_FILE) > 0 &&
1119	1154	defined($fingerprint)) {
1120		$LOG->info("~~Process ID (" . $$ . "):~~ Saving fingerprint to '" . $COMPROMISE_FILE . "'.");
	1155	$LOG->info("Saving fingerprint to '" . $COMPROMISE_FILE . "'.");
1121	1156	my $dump_file = new IO::File($COMPROMISE_FILE, "a");
1122	1157
…	…
1147	1182	my $result = undef;
1148	1183
1149		$LOG->info("~~Process ID (" . $$ . "):~~ Allowing VM (" . $self->{'quick_clone_vm_name'} . ") network access.");
	1184	$LOG->info("Allowing VM (" . $self->{'quick_clone_vm_name'} . ") network access.");
1150	1185
1151	1186	my $allowed_outbound_ports = getVar(name => "allowed_outbound_ports",
…	…
1184	1219	my $result = undef;
1185	1220
1186		$LOG->info("~~Process ID (" . $$ . "):~~ Denying VM (" . $self->{'quick_clone_vm_name'} . ") network access.");
	1221	$LOG->info("Denying VM (" . $self->{'quick_clone_vm_name'} . ") network access.");
1187	1222
1188	1223	($result, $self->{'_firewall_session'}) = HoneyClient::Manager::Firewall::Client->denyVM(session => $self->{'_firewall_session'}, chain_name => $self->{'quick_clone_vm_name'});
…	…
1192	1227	}
1193	1228
1194		$LOG->info("~~Process ID (" . $$ . "):~~ Destroying Packet Capture Session on VM (" . $self->{'quick_clone_vm_name'} . ").");
	1229	$LOG->info("Destroying Packet Capture Session on VM (" . $self->{'quick_clone_vm_name'} . ").");
1195	1230	($result, $self->{'_pcap_session'}) = HoneyClient::Manager::Pcap::Client->stopCapture(
1196	1231	session => $self->{'_pcap_session'},
…	…
1218	1253	if ($datastore_free < $min_space_free) {
1219	1254	my $datastore_free_in_gb = sprintf("%.2f", $datastore_free / (1024 * 1024 * 1024));
1220		$LOG->warn("Pr~~ocess ID (" . $$ . "): Pr~~imary datstore has low disk space (" . $datastore_free_in_gb . " GB).");
	1255	$LOG->warn("Primary datstore has low disk space (" . $datastore_free_in_gb . " GB).");
1221	1256	} else {
1222	1257	return;
1223	1258	}
1224		$LOG->info("~~Process ID (" . $$ . "):~~ Low disk space detected. Shutting down.");
	1259	$LOG->info("Low disk space detected. Shutting down.");
1225	1260	exit;
1226	1261	}
…	…
1241	1276	$self->_denyNetwork();
1242	1277
1243		$LOG->warn("~~Process ID (" . $$ . "):~~ Detected possible BSOD in initializing clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	1278	$LOG->warn("Detected possible BSOD in initializing clone VM (" . $self->{'quick_clone_vm_name'} . ").");
1244	1279
1245	1280	# Revert to default snapshot; upon revert, the VM will already be stopped.
1246		$LOG->info("~~Process ID (" . $$ . "):~~ Reverting clone VM (" . $self->{'quick_clone_vm_name'} . ") to snapshot (" . $args{'snapshot_name'} . ").");
	1281	$LOG->info("Reverting clone VM (" . $self->{'quick_clone_vm_name'} . ") to snapshot (" . $args{'snapshot_name'} . ").");
1247	1282	my $ret = HoneyClient::Manager::ESX->revertVM(session => $self->{'_vm_session'}, name => $self->{'quick_clone_vm_name'}, snapshot_name => $args{'snapshot_name'});
1248	1283	if (!$ret) {
1249		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to revert clone VM (" . $self->{'quick_clone_vm_name'} . "): Failed to revert to snapshot (" . $args{'snapshot_name'} . ").");
	1284	$LOG->error("Unable to revert clone VM (" . $self->{'quick_clone_vm_name'} . "): Failed to revert to snapshot (" . $args{'snapshot_name'} . ").");
1250	1285	Carp::croak "Unable to revert clone VM (" . $self->{'quick_clone_vm_name'} . "): Failed to revert to snapshot (" . $args{'snapshot_name'} . ").";
1251	1286	}
1252	1287	$self->{'_vm_session'} = $ret;
1253	1288
1254		$LOG->info("~~Process ID (" . $$ . "):~~ Starting clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	1289	$LOG->info("Starting clone VM (" . $self->{'quick_clone_vm_name'} . ").");
1255	1290	$self->{'_vm_session'} = HoneyClient::Manager::ESX->startVM(session => $self->{'_vm_session'}, name => $self->{'quick_clone_vm_name'});
1256	1291
…	…
1260	1295
1261	1296	# TODO: Delete this, eventually.
1262		$LOG->warn("Process ID (" . $$ . "): Clone VM (" . $self->{'quick_clone_vm_name'} . ") - _num_failed_inits: " . $self->{'_num_failed_inits'} . ".");
	1297	$LOG->warn("Clone VM (" . $self->{'quick_clone_vm_name'} . ") - _num_failed_inits: " . $self->{'_num_failed_inits'} . ".");
	1298	}
	1299	}
	1300
	1301	#######################################################################
	1302	# VIX Helper Methods #
	1303	#######################################################################
	1304
	1305	# Helper function to connect to the VMware ESX server, via VIX.
	1306	# Silently returns if already connected to a host.
	1307	# Dies upon any failure.
	1308	sub _vixConnectHost {
	1309	# Extract arguments.
	1310	my ($self, %args) = @_;
	1311
	1312	# VIX Temporary Variables.
	1313	my $vix_result = VIX_OK;
	1314
	1315	if ($self->{'_vix_host_handle'} == VIX_INVALID_HANDLE) {
	1316	$LOG->info("Obtaining VIX host handle.");
	1317	# Connect to the host.
	1318	my $vix_url = URI::URL->new_abs("/sdk", URI::URL->new($self->{'service_url'}));
	1319
	1320	# What do we do, when a VIX call times out.
	1321	local $SIG{ALRM} = sub {
	1322	die "VIX Timeout\n";
	1323	};
	1324
	1325	alarm($self->{'_vix_call_timeout'});
	1326	UNSAFE_SIGNALS {
	1327	($vix_result, $self->{'_vix_host_handle'}) = HostConnect(VIX_API_VERSION,
	1328	VIX_SERVICEPROVIDER_VMWARE_VI_SERVER,
	1329	$vix_url,
	1330	$vix_url->port,
	1331	$self->{'user_name'},
	1332	$self->{'password'},
	1333	0,
	1334	VIX_INVALID_HANDLE);
	1335	};
	1336	alarm(0);
	1337	if ($vix_result != VIX_OK) {
	1338	die "VIX::HostConnect() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1339	}
	1340	$self->{'_vix_host_updated_at'} = DateTime::HiRes->now();
	1341	}
	1342	}
	1343
	1344	# Helper function to connect to a VM the VMware ESX server, via VIX.
	1345	# Silently returns if already connected to a VM.
	1346	# Dies upon any failure.
	1347	sub _vixConnectVM {
	1348	# Extract arguments.
	1349	my ($self, %args) = @_;
	1350
	1351	# VIX Temporary Variables.
	1352	my $vix_result = VIX_OK;
	1353
	1354	if ($self->{'_vix_vm_handle'} == VIX_INVALID_HANDLE) {
	1355	$LOG->info("Obtaining VIX VM handle.");
	1356
	1357	# What do we do, when a VIX call times out.
	1358	local $SIG{ALRM} = sub {
	1359	die "VIX Timeout\n";
	1360	};
	1361
	1362	# Open the VM.
	1363	alarm($self->{'_vix_call_timeout'});
	1364	UNSAFE_SIGNALS {
	1365	($vix_result, $self->{'_vix_vm_handle'}) = VMOpen($self->{'_vix_host_handle'}, $self->{'config'});
	1366	};
	1367	alarm(0);
	1368	if ($vix_result != VIX_OK) {
	1369	die "VIX::VMOpen() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1370	}
	1371	$self->{'_vix_vm_updated_at'} = DateTime::HiRes->now();
	1372	}
	1373	}
	1374
	1375	# Helper function to disconnect from a VM on the VMware ESX server, via VIX.
	1376	# Logs any failure.
	1377	sub _vixDisconnectVM {
	1378	# Extract arguments.
	1379	my ($self, %args) = @_;
	1380
	1381	# VIX Temporary Variables.
	1382	my $vix_result = VIX_OK;
	1383
	1384	if (($self->{'_vix_vm_handle'} != VIX_INVALID_HANDLE) &&
	1385	(GetHandleType($self->{'_vix_vm_handle'}) == VIX_HANDLETYPE_VM)) {
	1386	$LOG->info("Releasing VIX VM Handle.");
	1387
	1388	# What do we do, when a VIX call times out.
	1389	local $SIG{ALRM} = sub {
	1390	# Issue an error on timeout, but continue.
	1391	$LOG->error("Error: VIX Timeout.");
	1392	};
	1393
	1394	alarm($self->{'_vix_call_timeout'});
	1395	UNSAFE_SIGNALS {
	1396	ReleaseHandle($self->{'_vix_vm_handle'});
	1397	};
	1398	alarm(0);
	1399	}
	1400	$self->{'_vix_vm_handle'} = VIX_INVALID_HANDLE;
	1401	}
	1402
	1403	# Helper function to disconnect from the VMware ESX server, via VIX.
	1404	# Logs any failure.
	1405	sub _vixDisconnectHost {
	1406	# Extract arguments.
	1407	my ($self, %args) = @_;
	1408
	1409	# VIX Temporary Variables.
	1410	my $vix_result = VIX_OK;
	1411
	1412	if (($self->{'_vix_host_handle'} != VIX_INVALID_HANDLE) &&
	1413	(GetHandleType($self->{'_vix_host_handle'}) == VIX_HANDLETYPE_HOST)) {
	1414	$LOG->info("Releasing VIX Host Handle.");
	1415
	1416	# What do we do, when a VIX call times out.
	1417	local $SIG{ALRM} = sub {
	1418	# Issue an error on timeout, but continue.
	1419	$LOG->error("Error: VIX Timeout.");
	1420	};
	1421
	1422	alarm($self->{'_vix_call_timeout'});
	1423	UNSAFE_SIGNALS {
	1424	HostDisconnect($self->{'_vix_host_handle'});
	1425	};
	1426	alarm(0);
	1427	}
	1428	$self->{'_vix_host_handle'} = VIX_INVALID_HANDLE;
	1429	}
	1430
	1431	# Helper function to indicate if the current host handle on the VMware ESX server is valid.
	1432	#
	1433	# Output: true if valid; false otherwise.
	1434	sub _vixIsHostValid {
	1435	# Extract arguments.
	1436	my ($self, %args) = @_;
	1437
	1438	# VIX Temporary Variables.
	1439	my $vix_result = VIX_OK;
	1440
	1441	# Find all registered VMs; if this call fails, then this handle is no longer valid.
	1442	eval {
	1443	my @vm_list = ();
	1444
	1445	# What do we do, when a VIX call times out.
	1446	local $SIG{ALRM} = sub {
	1447	die "VIX Timeout\n";
	1448	};
	1449
	1450	alarm($self->{'_vix_call_timeout'});
	1451	UNSAFE_SIGNALS {
	1452	@vm_list = FindItems($self->{'_vix_host_handle'}, VIX_FIND_REGISTERED_VMS, getVar(name => "timeout", namespace => "HoneyClient::Agent"));
	1453	};
	1454	alarm(0);
	1455	$vix_result = shift(@vm_list);
	1456	if ($vix_result != VIX_OK) {
	1457	die "VIX::FindItems() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1458	}
	1459	};
	1460	if ($@) {
	1461	return (0);
	1462	}
	1463	return (1);
	1464	}
	1465
	1466	# Helper function to indicate if the current VM handle on the VMware ESX server is valid.
	1467	#
	1468	# Output: true if valid; false otherwise.
	1469	sub _vixIsVMValid {
	1470	# Extract arguments.
	1471	my ($self, %args) = @_;
	1472
	1473	# VIX Temporary Variables.
	1474	my $vix_result = VIX_OK;
	1475
	1476	# Find all registered VMs; if this call fails, then this handle is no longer valid.
	1477	eval {
	1478	my $vm_power_state = undef;
	1479
	1480	# What do we do, when a VIX call times out.
	1481	local $SIG{ALRM} = sub {
	1482	die "VIX Timeout\n";
	1483	};
	1484
	1485	alarm($self->{'_vix_call_timeout'});
	1486	UNSAFE_SIGNALS {
	1487	($vix_result, $vm_power_state) = GetProperties($self->{'_vix_vm_handle'},
	1488	VIX_PROPERTY_VM_POWER_STATE);
	1489	};
	1490	alarm(0);
	1491	if ($vix_result != VIX_OK) {
	1492	die "VIX::GetProperties() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1493	}
	1494	};
	1495	if ($@) {
	1496	return (0);
	1497	}
	1498	return (1);
	1499	}
	1500
	1501	# Helper function to validate both the host and VM handles.
	1502	# Dies upon any failures.
	1503	sub _vixValidateHandles {
	1504	# Extract arguments.
	1505	my ($self, %args) = @_;
	1506
	1507	# VIX Temporary Variables.
	1508	my $vix_result = VIX_OK;
	1509
	1510	# Validate current host, if older than the given threshold.
	1511	if ((DateTime::HiRes->now() - DateTime::Duration->new(seconds => getVar(name => "session_timeout"))) > $self->{'_vix_host_updated_at'}) {
	1512	if (!$self->_vixIsHostValid()) {
	1513	# Reconnect host and VM, if host is not valid.
	1514	$self->_vixDisconnectVM();
	1515	$self->_vixDisconnectHost();
	1516	$self->_vixConnectHost();
	1517	$self->_vixConnectVM();
	1518	} else {
	1519	# Host remains valid; update timestamp.
	1520	$self->{'_vix_host_updated_at'} = DateTime::HiRes->now();
	1521	}
	1522	}
	1523
	1524	# Validate current VM, if older than the given threshold.
	1525	if ((DateTime::HiRes->now() - DateTime::Duration->new(seconds => getVar(name => "session_timeout"))) > $self->{'_vix_vm_updated_at'}) {
	1526	if (!$self->_vixIsVMValid()) {
	1527	# Reconnect VM, if VM is not valid.
	1528	$self->_vixDisconnectVM();
	1529	$self->_vixConnectVM();
	1530	} else {
	1531	# Session remains valid; update timestamp.
	1532	$self->{'_vix_vm_updated_at'} = DateTime::HiRes->now();
	1533	}
	1534	}
	1535	}
	1536
	1537	# Helper function to wait for VMware Tools and
	1538	# log into the Guest OS on the VM.
	1539	# Dies upon any failures.
	1540	sub _vixLoginInGuest {
	1541	# Extract arguments.
	1542	my ($self, %args) = @_;
	1543
	1544	# VIX Temporary Variables.
	1545	my $vix_result = VIX_OK;
	1546
	1547	# Sanity check.
	1548	$self->_vixValidateHandles();
	1549
	1550	$LOG->info("Waiting for VMware Tools.");
	1551
	1552	# What do we do, when a VIX call times out.
	1553	local $SIG{ALRM} = sub {
	1554	die "VIX Timeout\n";
	1555	};
	1556
	1557	# Make sure we can access VMware Tools.
	1558	alarm($self->{'_vix_call_timeout'});
	1559	UNSAFE_SIGNALS {
	1560	$vix_result = VMWaitForToolsInGuest($self->{'_vix_vm_handle'}, getVar(name => "timeout", namespace => "HoneyClient::Agent"));
	1561	};
	1562	alarm(0);
	1563	if ($vix_result != VIX_OK) {
	1564	die "VIX::VMWaitForToolsInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1565	}
	1566
	1567	$LOG->info("Logging into guest OS.");
	1568
	1569	# What do we do, when a VIX call times out.
	1570	local $SIG{ALRM} = sub {
	1571	die "VIX Timeout\n";
	1572	};
	1573
	1574	# Login to guest OS.
	1575	alarm($self->{'_vix_call_timeout'});
	1576	UNSAFE_SIGNALS {
	1577	$vix_result = VMLoginInGuest($self->{'_vix_vm_handle'},
	1578	$self->{'guest_user_name'},
	1579	$self->{'guest_password'},
	1580	VIX_LOGIN_IN_GUEST_REQUIRE_INTERACTIVE_ENVIRONMENT);
	1581	};
	1582	alarm(0);
	1583	if ($vix_result != VIX_OK) {
	1584	die "VIX::VMLoginInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1585	}
	1586	}
	1587
	1588	# Helper function to maximize the application in the VM.
	1589	# Dies upon any failures.
	1590	sub _vixMaximizeApplication {
	1591	# Extract arguments.
	1592	my ($self, %args) = @_;
	1593
	1594	# VIX Temporary Variables.
	1595	my $vix_result = VIX_OK;
	1596
	1597	# Sanity check.
	1598	$self->_vixValidateHandles();
	1599
	1600	$LOG->info("Setting application to open in maximized mode.");
	1601	if (!defined($self->{'_maximize_registry_file'})) {
	1602	# What do we do, when a VIX call times out.
	1603	local $SIG{ALRM} = sub {
	1604	die "VIX Timeout\n";
	1605	};
	1606	alarm($self->{'_vix_call_timeout'});
	1607	UNSAFE_SIGNALS {
	1608	($vix_result, $self->{'_maximize_registry_file'}) = VMCreateTempFileInGuest($self->{'_vix_vm_handle'}, 0, VIX_INVALID_HANDLE);
	1609	};
	1610	alarm(0);
	1611	if ($vix_result != VIX_OK) {
	1612	die "VIX::VMCreateTempFileInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1613	}
	1614
	1615	# What do we do, when a VIX call times out.
	1616	local $SIG{ALRM} = sub {
	1617	die "VIX Timeout\n";
	1618	};
	1619	alarm($self->{'_vix_call_timeout'});
	1620	UNSAFE_SIGNALS {
	1621	$vix_result = VMCopyFileFromHostToGuest($self->{'_vix_vm_handle'},
	1622	getVar(name => "maximize_registry", namespace => $self->{'driver_name'}),
	1623	$self->{'_maximize_registry_file'},
	1624	0,
	1625	VIX_INVALID_HANDLE);
	1626	};
	1627	alarm(0);
	1628	if ($vix_result != VIX_OK) {
	1629	die "VIX::VMCopyFileFromHostToGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1630	}
	1631	}
	1632
	1633	# What do we do, when a VIX call times out.
	1634	local $SIG{ALRM} = sub {
	1635	die "VIX Timeout\n";
	1636	};
	1637	alarm($self->{'_vix_call_timeout'});
	1638	UNSAFE_SIGNALS {
	1639	$vix_result = VMRunProgramInGuest($self->{'_vix_vm_handle'},
	1640	# TODO: Should probably not hard-code this path.
	1641	'C:\WINDOWS\System32\cmd.exe',
	1642	'/C reg import ' . $self->{'_maximize_registry_file'},
	1643	0,
	1644	VIX_INVALID_HANDLE);
	1645	};
	1646	alarm(0);
	1647	if ($vix_result != VIX_OK) {
	1648	die "VIX::VMRunProgramInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1649	}
	1650	}
	1651
	1652	# Helper function to drive the application in the VM.
	1653	#
	1654	# Input: url
	1655	#
	1656	# Dies upon any failures.
	1657	sub _vixDriveApplication {
	1658	# Extract arguments.
	1659	my ($self, %args) = @_;
	1660
	1661	# VIX Temporary Variables.
	1662	my $vix_result = VIX_OK;
	1663
	1664	# Sanity check.
	1665	$self->_vixValidateHandles();
	1666
	1667	$LOG->info("Driving the application.");
	1668
	1669	# What do we do, when a VIX call times out.
	1670	local $SIG{ALRM} = sub {
	1671	die "VIX Timeout\n";
	1672	};
	1673	alarm($self->{'_vix_call_timeout'});
	1674	UNSAFE_SIGNALS {
	1675	$vix_result = VMOpenUrlInGuest($self->{'_vix_vm_handle'}, $args{'url'}, 0, VIX_INVALID_HANDLE);
	1676	};
	1677	alarm(0);
	1678	if ($vix_result != VIX_OK) {
	1679	die "VIX::VMOpenUrlInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1680	}
	1681	}
	1682
	1683	# Helper function to capture the screen of the VM.
	1684	# Dies upon any failures.
	1685	sub _vixCaptureScreenImage {
	1686	# Extract arguments.
	1687	my ($self, %args) = @_;
	1688
	1689	# VIX Temporary Variables.
	1690	my $vix_result = VIX_OK;
	1691
	1692	# Sanity check.
	1693	$self->_vixValidateHandles();
	1694
	1695	# What do we do, when a VIX call times out.
	1696	local $SIG{ALRM} = sub {
	1697	die "VIX Timeout\n";
	1698	};
	1699	my $vix_image_size = undef;
	1700	alarm($self->{'_vix_call_timeout'});
	1701	UNSAFE_SIGNALS {
	1702	($vix_result, $vix_image_size, $self->{'_vix_image_bytes'}) = VMCaptureScreenImage($self->{'_vix_vm_handle'},
	1703	VIX_CAPTURESCREENFORMAT_PNG,
	1704	VIX_INVALID_HANDLE);
	1705	};
	1706	alarm(0);
	1707	if ($vix_result != VIX_OK) {
	1708	die "VIX::VMCaptureScreenImage() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1709	}
	1710	}
	1711
	1712	# Helper function to close the application in the VM.
	1713	# Dies upon any failures.
	1714	sub _vixCloseApplication {
	1715	# Extract arguments.
	1716	my ($self, %args) = @_;
	1717
	1718	# VIX Temporary Variables.
	1719	my $vix_result = VIX_OK;
	1720
	1721	# Sanity check.
	1722	$self->_vixValidateHandles();
	1723
	1724	$LOG->info("Listing processes in guest OS.");
	1725	# What do we do, when a VIX call times out.
	1726	local $SIG{ALRM} = sub {
	1727	die "VIX Timeout\n";
	1728	};
	1729	my @vix_process_properties = ();
	1730	alarm($self->{'_vix_call_timeout'});
	1731	UNSAFE_SIGNALS {
	1732	($vix_result, @vix_process_properties) = VMListProcessesInGuest($self->{'_vix_vm_handle'}, 0);
	1733	};
	1734	alarm(0);
	1735	if ($vix_result != VIX_OK) {
	1736	die "VIX::VMListProcessesInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1737	}
	1738
	1739	foreach my $property (@vix_process_properties) {
	1740	if (($property->{'PROCESS_OWNER'} ne "NT AUTHORITY\\SYSTEM") &&
	1741	($property->{'PROCESS_NAME'} eq getVar(name => "process_name", namespace => $self->{'driver_name'}))) {
	1742	$LOG->info("Terminating application.");
	1743	# What do we do, when a VIX call times out.
	1744	local $SIG{ALRM} = sub {
	1745	die "VIX Timeout\n";
	1746	};
	1747	alarm($self->{'_vix_call_timeout'});
	1748	UNSAFE_SIGNALS {
	1749	$vix_result = VMKillProcessInGuest($self->{'_vix_vm_handle'}, $property->{'PROCESS_ID'}, 0);
	1750	};
	1751	alarm(0);
	1752	if ($vix_result != VIX_OK) {
	1753	die "VIX::VMKillProcessInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1754	}
	1755	} elsif ($property->{'PROCESS_NAME'} eq getVar(name => "process_name", namespace => $self->{'driver_name'})) {
	1756
	1757	# XXX: This method is hideously slow, but we have no choice, because if we try to kill an application
	1758	# (using VIX), which is running as "NT AUTHORITY\SYSTEM", we will get permission denied issues.
	1759	# Thankfully, this code will only run for ESX 3.5U4 and earlier deployments -- as VMware fixed this
	1760	# issue in ESX 4.0.
	1761
	1762	$LOG->info("Terminating application.");
	1763	# What do we do, when a VIX call times out.
	1764	local $SIG{ALRM} = sub {
	1765	die "VIX Timeout\n";
	1766	};
	1767	alarm($self->{'_vix_call_timeout'});
	1768	UNSAFE_SIGNALS {
	1769	$vix_result = VMRunProgramInGuest($self->{'_vix_vm_handle'},
	1770	# TODO: Probably should not hard code this path.
	1771	'C:\WINDOWS\System32\taskkill.exe',
	1772	'/F /IM ' . getVar(name => "process_name", namespace => $self->{'driver_name'}) . ' /T',
	1773	0,
	1774	VIX_INVALID_HANDLE);
	1775	};
	1776	alarm(0);
	1777	if ($vix_result != VIX_OK) {
	1778	die "VIX::VMRunProgramInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1779	}
	1780	}
	1781	}
	1782	}
	1783
	1784	# Helper function to copy a file out of a VM.
	1785	#
	1786	# Inputs: guest_filename, host_filename
	1787	#
	1788	# Dies upon any failures.
	1789	sub _vixCopyFileFromGuestToHost {
	1790	# Extract arguments.
	1791	my ($self, %args) = @_;
	1792
	1793	# VIX Temporary Variables.
	1794	my $vix_result = VIX_OK;
	1795
	1796	# Sanity check.
	1797	$self->_vixValidateHandles();
	1798
	1799	# What do we do, when a VIX call times out.
	1800	local $SIG{ALRM} = sub {
	1801	die "VIX Timeout\n";
	1802	};
	1803	alarm($self->{'_vix_call_timeout'});
	1804	UNSAFE_SIGNALS {
	1805	$vix_result = VMCopyFileFromGuestToHost($self->{'_vix_vm_handle'},
	1806	$args{'guest_filename'},
	1807	$args{'host_filename'},
	1808	0,
	1809	VIX_INVALID_HANDLE);
	1810	};
	1811	alarm(0);
	1812	if ($vix_result != VIX_OK) {
	1813	die "VIX::VMCopyFileFromGuestToHost() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
	1814	}
	1815	}
	1816
	1817	# Helper function to log out of a Guest OS on the VM.
	1818	# Dies upon any failures.
	1819	sub _vixLogoutFromGuest {
	1820	# Extract arguments.
	1821	my ($self, %args) = @_;
	1822
	1823	# VIX Temporary Variables.
	1824	my $vix_result = VIX_OK;
	1825
	1826	# Sanity check.
	1827	$self->_vixValidateHandles();
	1828
	1829	$LOG->info("Logging off guest OS.");
	1830
	1831	# What do we do, when a VIX call times out.
	1832	local $SIG{ALRM} = sub {
	1833	die "VIX Timeout\n";
	1834	};
	1835
	1836	# Logout from guest OS.
	1837	alarm($self->{'_vix_call_timeout'});
	1838	UNSAFE_SIGNALS {
	1839	$vix_result = VMLogoutFromGuest($self->{'_vix_vm_handle'});
	1840	};
	1841	alarm(0);
	1842	if ($vix_result != VIX_OK) {
	1843	die "VIX::VMLogoutFromGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
1263	1844	}
1264	1845	}
…	…
1440	2021	status => "uninitialized",
1441	2022
1442		# A variable reflected the driver assigned to this cloned VM.
	2023	# A variable reflecting the driver assigned to this cloned VM.
1443	2024	driver_name => getVar(name => "default_driver",
1444	2025	namespace => "HoneyClient::Agent"),
…	…
1503	2084	# always display in a maximized state.
1504	2085	_maximize_registry_file => undef,
	2086
	2087	# A VIX host handle, used when accessing the VMware ESX server remotely.
	2088	# (This internal variable should never be modified externally.)
	2089	_vix_host_handle => VIX_INVALID_HANDLE,
	2090
	2091	# A VIX VM handle, used when accessing the VM on the VMware ESX server
	2092	# remotely. (This internal variable should never be modified externally.)
	2093	_vix_vm_handle => VIX_INVALID_HANDLE,
	2094
	2095	# A buffer, used to store the latest screenshot acquired via VIX.
	2096	# (This internal variable should never be modified externally.)
	2097	_vix_image_bytes => undef,
	2098
	2099	# A variable indicating how long to wait for each VIX call to finish.
	2100	# (This internal variable should never be modified externally.)
	2101	_vix_call_timeout => getVar(name => "vix_timeout"),
	2102
	2103	# A variable, indicating when the last time the VIX host handle was updated.
	2104	# (This internal variable should never be modified externally.)
	2105	_vix_host_updated_at => undef,
	2106
	2107	# A variable, indicating when the last time the VIX VM handle was updated.
	2108	# (This internal variable should never be modified externally.)
	2109	_vix_vm_updated_at => undef,
1505	2110	);
1506	2111
…	…
1516	2121	# Sanity check: Make sure guest OS username/password credentials were provided.
1517	2122	if (!defined($self->{'guest_user_name'})) {
1518		$LOG->error("~~Process ID (" . $$ . "):~~ Guest OS user name was not provided. Unable to continue.");
	2123	$LOG->error("Guest OS user name was not provided. Unable to continue.");
1519	2124	Carp::croak "Guest OS user name was not provided. Unable to continue.";
1520	2125	}
1521	2126	if (!defined($self->{'guest_password'})) {
1522		$LOG->error("~~Process ID (" . $$ . "):~~ Guest OS password was not provided. Unable to continue.");
	2127	$LOG->error("Guest OS password was not provided. Unable to continue.");
1523	2128	Carp::croak "Guest OS password was not provided. Unable to continue.";
1524	2129	}
…	…
1541	2146	# Set a valid handle for the VM daemon.
1542	2147	if (!defined($self->{'_vm_session'})) {
1543		$LOG->info("~~Process ID (" . $$ . "):~~ Creating a new ESX session to (" . $self->{'service_url'} . ").");
	2148	$LOG->info("Creating a new ESX session to (" . $self->{'service_url'} . ").");
1544	2149	$self->{'_vm_session'} = HoneyClient::Manager::ESX->login(
1545	2150	service_url => $self->{'service_url'},
…	…
1563	2168	# Sanity check: Make sure there is enough disk space available.
1564	2169	$self->_checkSpaceAvailable();
	2170
	2171	# Connect (or reconnect) to host via VIX, if enabled.
	2172	if (getVar(name => "vix_enable")) {
	2173	eval {
	2174	$self->_vixDisconnectVM();
	2175	$self->_vixDisconnectHost();
	2176	$self->_vixConnectHost();
	2177	};
	2178	if ($@) {
	2179	$LOG->error("Unable to connect to host. " . $@);
	2180	Carp::croak "Unable to connect to host. " . $@;
	2181	}
	2182	}
1565	2183
1566	2184	# Determine if the firewall needs to be bypassed.
…	…
1575	2193
1576	2194	# If so, then suspend the existing quick clone.
1577		$LOG->info("~~Process ID (" . $$ . "):~~ Suspending clone VM (" . $self->{'quick_clone_vm_name'} . ") - reached maximum number of snapshots (" . $self->{'_num_snapshots'} . ").");
	2195	$LOG->info("Suspending clone VM (" . $self->{'quick_clone_vm_name'} . ") - reached maximum number of snapshots (" . $self->{'_num_snapshots'} . ").");
1578	2196	my $som = undef;
1579	2197	eval {
…	…
1581	2199	};
1582	2200	if ($@ \|\| !defined($som)) {
1583		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . "). " . $@);
	2201	$LOG->error("Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . "). " . $@);
1584	2202	} else {
1585	2203	$self->{'_vm_session'} = $som;
…	…
1604	2222	};
1605	2223	if ($@) {
1606		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to initialize VM (" . $self->{'quick_clone_vm_name'} . ") - Retrying operation. " . $@);
	2224	$LOG->error("Unable to initialize VM (" . $self->{'quick_clone_vm_name'} . ") - Retrying operation. " . $@);
1607	2225	# TODO: Make sure this works!
1608	2226	#$DB::single = 1;
1609	2227
1610	2228	# Make sure the old VM is at least suspended, before attempting to clone another one.
1611		$LOG->info("~~Process ID (" . $$ . "):~~ Suspending clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	2229	$LOG->info("Suspending clone VM (" . $self->{'quick_clone_vm_name'} . ").");
1612	2230	my $som = undef;
1613	2231	my $suspended_at = undef;
…	…
1618	2236
1619	2237	if (!defined($som)) {
1620		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . ").");
	2238	$LOG->error("Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . ").");
1621	2239	} else {
1622	2240	$self->{'_vm_session'} = $som;
…	…
1629	2247	$self->_changeStatus(status => "error");
1630	2248	$self = $new_self;
	2249	}
	2250	# Connect to VM and login via VIX, if enabled.
	2251	if (getVar(name => "vix_enable")) {
	2252	eval {
	2253	$self->_vixConnectVM();
	2254	$self->_vixLoginInGuest();
	2255	};
	2256	if ($@) {
	2257	$LOG->error("Unable to connect and login to VM. " . $@);
	2258	Carp::croak "Unable to connect and login to VM. " . $@;
	2259	}
1631	2260	}
1632	2261	return $self;
…	…
1771	2400	# Snapshot the VM.
1772	2401	if ($args{'perform_snapshot'}) {
1773		$LOG->info("~~Process ID (" . $$ . "):~~ Saving operational snapshot (" . $self->{'name'} . ") of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	2402	$LOG->info("Saving operational snapshot (" . $self->{'name'} . ") of clone VM (" . $self->{'quick_clone_vm_name'} . ").");
1774	2403	my $som = undef;
1775	2404	my $suspended_at = undef;
…	…
1783	2412	};
1784	2413	if ($@ \|\| !defined($som)) {
1785		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to save operational snapshot (" . $self->{'name'} . ") on clone VM (" . $self->{'quick_clone_vm_name'} . "). " . $@);
	2414	$LOG->error("Unable to save operational snapshot (" . $self->{'name'} . ") on clone VM (" . $self->{'quick_clone_vm_name'} . "). " . $@);
1786	2415	# Try at least to suspend the VM, when an error occurs.
1787	2416	eval {
…	…
1789	2418	};
1790	2419	if (!defined($som)) {
1791		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . ").");
	2420	$LOG->error("Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . ").");
1792	2421	} else {
1793	2422	$self->{'_vm_session'} = $som;
…	…
1920	2549	# original name; that way, it's equivalent to deletion. We assume the operational snapshot
1921	2550	# will then be reverted and renamed to the next valid operational snapshot name.
1922		$LOG->info("~~Process ID (" . $$ . "):~~ Destroying snapshot (" . $self->{'name'} . ") on clone VM (" . $self->{'quick_clone_vm_name'} . ").");
	2551	$LOG->info("Destroying snapshot (" . $self->{'name'} . ") on clone VM (" . $self->{'quick_clone_vm_name'} . ").");
1923	2552	my $som = undef;
1924	2553	eval {
…	…
1931	2560	};
1932	2561	if ($@ \|\| !defined($som)) {
1933		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to remove snapshot (" . $self->{'name'} . ") on clone VM (" . $self->{'quick_clone_vm_name'} . "). " . $@);
	2562	$LOG->error("Unable to remove snapshot (" . $self->{'name'} . ") on clone VM (" . $self->{'quick_clone_vm_name'} . "). " . $@);
1934	2563	# Try at least to suspend the VM, when an error occurs.
1935	2564	eval {
…	…
1937	2566	};
1938	2567	if (!defined($som)) {
1939		$LOG->error("~~Process ID (" . $$ . "):~~ Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . ").");
	2568	$LOG->error("Unable to suspend VM (" . $self->{'quick_clone_vm_name'} . ").");
1940	2569	} else {
1941	2570	$self->{'_vm_session'} = $som;
…	…
2060	2689
2061	2690	# Croak if no valid argument is supplied.
2062		$LOG->error("~~Process ID (" . $$ . "):~~ Error: Invalid job supplied.");
	2691	$LOG->error("Error: Invalid job supplied.");
2063	2692	Carp::croak "Error: Invalid job supplied.";
2064	2693	}
2065	2694
2066		$LOG->info("Process ~~ID (" . $$ . "): Process~~ing Job (" . $args{'job'}->uuid() . ").");
	2695	$LOG->info("Processing Job (" . $args{'job'}->uuid() . ").");
2067	2696
2068	2697	# Record the start time of the job (in seconds).
…	…
2120	2749	($self->{'work_units_processed'} >= getVar(name => "work_unit_limit"))) {
2121	2750
2122		$LOG->info("~~Process ID (" . $$ . "):~~ (" . $self->{'quick_clone_vm_name'} . ") - Work Unit Limit Reached (" . getVar(name => "work_unit_limit") . "). Recycling clone VM.");
	2751	$LOG->info("(" . $self->{'quick_clone_vm_name'} . ") - Work Unit Limit Reached (" . getVar(name => "work_unit_limit") . "). Recycling clone VM.");
2123	2752	$self->destroy();
2124	2753	}
…	…
2145	2774	user_name => $self->{'user_name'},
2146	2775	password => $self->{'password'},
	2776	_vix_host_handle => $self->{'_vix_host_handle'},
	2777	_vix_call_timeout => $self->{'_vix_call_timeout'},
	2778	_vix_host_updated_at => $self->{'_vix_host_updated_at'},
2147	2779	);
2148	2780
…	…
2170	2802
2171	2803	my $capture_result = undef;
2172		$LOG->info("~~Process ID (" . $$ . "):~~ Starting Packet Capture Session on VM (" . $self->{'quick_clone_vm_name'} . ").");
	2804	$LOG->info("Starting Packet Capture Session on VM (" . $self->{'quick_clone_vm_name'} . ").");
2173	2805	($capture_result, $self->{'_pcap_session'}) = HoneyClient::Manager::Pcap::Client->startCapture(
2174	2806	session => $self->{'_pcap_session'},
…	…
2179	2811	$result = undef;
2180	2812	# VIX Temporary Variables.
2181		~~my $vix_result = VIX_OK;~~
2182		~~my $vix_host_handle = VIX_INVALID_HANDLE;~~
2183		~~my $vix_vm_handle = VIX_INVALID_HANDLE;~~
2184		~~my @vix_process_properties = ();~~
2185		~~my $vix_image_size = undef;~~
2186		~~my $vix_image_bytes = undef;~~
2187	2813	my $vix_driver_timeout = getVar(name => "timeout",
2188	2814	namespace => "HoneyClient::Agent::Driver");
2189		~~my $vix_call_timeout = getVar(name => "vix_timeout");~~
2190	2815	eval {
2191		# What do we do, when a VIX call times out.
2192		local $SIG{ALRM} = sub {
2193		die "VIX Timeout\n";
2194		};
2195
2196		$LOG->info("Process ID (" . $$ . "): (" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Driving To Resource: " . $url->url());
	2816	$LOG->info("(" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Driving To Resource: " . $url->url());
2197	2817	$self->{'work_units_processed'}++;
2198	2818
…	…
2212	2832	# Sanity checks.
2213	2833	if ($url->wait_id() > $agent_max_timeout) {
2214		$LOG->warn("~~Process ID (" . $$ . "):~~ (" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Ignoring Invalid Timeout (" . $url->wait_id() . ") - Using Timeout Value (" . $agent_max_timeout . ")");
	2834	$LOG->warn("(" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Ignoring Invalid Timeout (" . $url->wait_id() . ") - Using Timeout Value (" . $agent_max_timeout . ")");
2215	2835	$vix_driver_timeout = $agent_max_timeout;
2216	2836	} elsif ($url->wait_id() < $agent_min_timeout) {
2217		$LOG->warn("~~Process ID (" . $$ . "):~~ (" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Ignoring Invalid Timeout (" . $url->wait_id() . ") - Using Timeout Value (" . $agent_min_timeout . ")");
	2837	$LOG->warn("(" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Ignoring Invalid Timeout (" . $url->wait_id() . ") - Using Timeout Value (" . $agent_min_timeout . ")");
2218	2838	$vix_driver_timeout = $agent_min_timeout;
2219	2839	} else {
…	…
2222	2842	}
2223	2843
2224		$LOG->info("Process ID (" . $$ . "): Obtaining VIX host handle.");
2225		# Connect to the host.
2226		my $vix_url = URI::URL->new_abs("/sdk", URI::URL->new($self->{'service_url'}));
2227		alarm($vix_call_timeout);
2228		UNSAFE_SIGNALS {
2229		($vix_result, $vix_host_handle) = HostConnect(VIX_API_VERSION,
2230		VIX_SERVICEPROVIDER_VMWARE_VI_SERVER,
2231		$vix_url,
2232		$vix_url->port,
2233		$self->{'user_name'},
2234		$self->{'password'},
2235		0,
2236		VIX_INVALID_HANDLE);
2237		if ($vix_result != VIX_OK) {
2238		die "VIX::HostConnect() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2239		}
2240		};
2241		alarm(0);
2242
2243		$LOG->info("Process ID (" . $$ . "): Obtaining VIX VM handle.");
2244		# Open the VM.
2245		alarm($vix_call_timeout);
2246		UNSAFE_SIGNALS {
2247		($vix_result, $vix_vm_handle) = VMOpen($vix_host_handle, $self->{'config'});
2248		if ($vix_result != VIX_OK) {
2249		die "VIX::VMOpen() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2250		}
2251		};
2252		alarm(0);
2253
2254		$LOG->info("Process ID (" . $$ . "): Waiting for VMware Tools.");
2255		# Make sure we can access VMware Tools.
2256		alarm($vix_call_timeout);
2257		UNSAFE_SIGNALS {
2258		$vix_result = VMWaitForToolsInGuest($vix_vm_handle, getVar(name => "timeout", namespace => "HoneyClient::Agent"));
2259		if ($vix_result != VIX_OK) {
2260		die "VIX::VMWaitForToolsInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2261		}
2262		};
2263		alarm(0);
2264
2265		$LOG->info("Process ID (" . $$ . "): Logging into guest OS.");
2266		# Login to guest OS.
2267		alarm($vix_call_timeout);
2268		UNSAFE_SIGNALS {
2269		$vix_result = VMLoginInGuest($vix_vm_handle,
2270		$self->{'guest_user_name'},
2271		$self->{'guest_password'},
2272		VIX_LOGIN_IN_GUEST_REQUIRE_INTERACTIVE_ENVIRONMENT); # options
2273		if ($vix_result != VIX_OK) {
2274		die "VIX::VMLoginInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2275		}
2276		};
2277		alarm(0);
	2844	# XXX: Cleanup.
	2845	# $self->_vixConnectHost();
	2846	# $self->_vixConnectVM();
	2847	# $self->_vixLoginInGuest();
2278	2848
2279	2849	# If a 'load complete' image was defined and the 'end early' flag was specified and true,
…	…
2288	2858
2289	2859	# As such, make sure the target application is always maximized.
2290		$LOG->info("Process ID (" . $$ . "): Setting application to open in maximized mode.");
2291		if (!defined($self->{'_maximize_registry_file'})) {
2292		alarm($vix_call_timeout);
2293		UNSAFE_SIGNALS {
2294		($vix_result, $self->{'_maximize_registry_file'}) = VMCreateTempFileInGuest($vix_vm_handle, 0, VIX_INVALID_HANDLE);
2295		if ($vix_result != VIX_OK) {
2296		die "VIX::VMCreateTempFileInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2297		}
2298		};
2299		alarm(0);
2300		alarm($vix_call_timeout);
2301		UNSAFE_SIGNALS {
2302		$vix_result = VMCopyFileFromHostToGuest($vix_vm_handle,
2303		getVar(name => "maximize_registry", namespace => $self->{'driver_name'}),
2304		$self->{'_maximize_registry_file'},
2305		0,
2306		VIX_INVALID_HANDLE);
2307		if ($vix_result != VIX_OK) {
2308		die "VIX::VMCopyFileFromHostToGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2309		}
2310		};
2311		alarm(0);
2312
2313		}
2314		alarm($vix_call_timeout);
2315		UNSAFE_SIGNALS {
2316		$vix_result = VMRunProgramInGuest($vix_vm_handle,
2317		'C:\WINDOWS\System32\cmd.exe',
2318		'/C reg import ' . $self->{'_maximize_registry_file'},
2319		0,
2320		VIX_INVALID_HANDLE);
2321		if ($vix_result != VIX_OK) {
2322		die "VIX::VMRunProgramInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2323		}
2324		};
2325		alarm(0);
	2860	$self->_vixMaximizeApplication();
2326	2861	}
2327	2862
2328		~~$LOG->info("Process ID (" . $$ . "): Driving the application.");~~
2329	2863	# Drive the browser.
2330	2864	my $visit_start_time = time;
2331		alarm($vix_call_timeout);
2332		UNSAFE_SIGNALS {
2333		$vix_result = VMOpenUrlInGuest($vix_vm_handle, $url->url(), 0, VIX_INVALID_HANDLE);
2334		if ($vix_result != VIX_OK) {
2335		die "VIX::VMOpenUrlInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2336		}
2337		};
2338		alarm(0);
	2865	$self->_vixDriveApplication(url => $url->url());
	2866
2339	2867	# Adjust $vix_driver_timeout to account for load delay.
2340	2868	$vix_driver_timeout = $vix_driver_timeout - (time - $visit_start_time);
…	…
2368	2896
2369	2897	# Acquire sample.
2370		$LOG->info("Process ID (" . $$ . "): Checking if content has fully rendered.");
2371		alarm($vix_call_timeout);
2372		UNSAFE_SIGNALS {
2373		($vix_result, $vix_image_size, $vix_image_bytes) = VMCaptureScreenImage($vix_vm_handle,
2374		VIX_CAPTURESCREENFORMAT_PNG,
2375		VIX_INVALID_HANDLE);
2376		if ($vix_result != VIX_OK) {
2377		die "VIX::VMCaptureScreenImage() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2378		}
2379		};
2380		alarm(0);
2381		open (my $IMAGE_DATA, "<:scalar", \$vix_image_bytes) or
	2898	$LOG->info("Checking if content has fully rendered.");
	2899	$self->_vixCaptureScreenImage();
	2900	open (my $IMAGE_DATA, "<:scalar", \$self->{'_vix_image_bytes'}) or
2382	2901	die "Unable to extract VM screenshot contents. " . $!;
2383	2902	my $screenshot = Prima::Image->load($IMAGE_DATA);
…	…
2390	2909	my ($x,$y) = $status_bar->match($self->{'load_complete_image'});
2391	2910	if (defined($x) && defined($y)) {
2392		$LOG->info("~~Process ID (" . $$ . "):~~ Load complete.");
	2911	$LOG->info("Load complete.");
2393	2912	$load_complete = 1;
2394	2913	last;
…	…
2408	2927
2409	2928	# Take a screenshot, if asked.
2410		if (!defined($vix_image_bytes) && $url->has_screenshot_id() && $url->screenshot_id()) {
2411		$LOG->info("Process ID (" . $$ . "): Taking screenshot.");
2412		alarm($vix_call_timeout);
2413		UNSAFE_SIGNALS {
2414		($vix_result, $vix_image_size, $vix_image_bytes) = VMCaptureScreenImage($vix_vm_handle,
2415		VIX_CAPTURESCREENFORMAT_PNG,
2416		VIX_INVALID_HANDLE);
2417		if ($vix_result != VIX_OK) {
2418		die "VIX::VMCaptureScreenImage() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2419		}
2420		};
2421		alarm(0);
	2929	if (!defined($self->{'_vix_image_bytes'}) && $url->has_screenshot_id() && $url->screenshot_id()) {
	2930	$LOG->info("Taking screenshot.");
	2931	$self->_vixCaptureScreenImage();
2422	2932	}
2423	2933
…	…
2432	2942	!$url->has_reuse_browser_id() \|\|
2433	2943	!$url->reuse_browser_id())) {
2434		$LOG->info("Process ID (" . $$ . "): Listing processes in guest OS.");
2435		alarm($vix_call_timeout);
2436		UNSAFE_SIGNALS {
2437		($vix_result, @vix_process_properties) = VMListProcessesInGuest($vix_vm_handle, 0);
2438		if ($vix_result != VIX_OK) {
2439		die "VIX::VMListProcessesInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2440		}
2441		};
2442		alarm(0);
2443
2444		foreach my $property (@vix_process_properties) {
2445		if (($property->{'PROCESS_OWNER'} ne "NT AUTHORITY\\SYSTEM") &&
2446		($property->{'PROCESS_NAME'} eq getVar(name => "process_name", namespace => $self->{'driver_name'}))) {
2447		$LOG->info("Process ID (" . $$ . "): Terminating application.");
2448		alarm($vix_call_timeout);
2449		UNSAFE_SIGNALS {
2450		$vix_result = VMKillProcessInGuest($vix_vm_handle, $property->{'PROCESS_ID'}, 0);
2451		if ($vix_result != VIX_OK) {
2452		die "VIX::VMKillProcessInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2453		}
2454		};
2455		alarm(0);
2456		} elsif ($property->{'PROCESS_NAME'} eq getVar(name => "process_name", namespace => $self->{'driver_name'})) {
2457		$LOG->info("Process ID (" . $$ . "): Terminating application.");
2458		alarm($vix_call_timeout);
2459		UNSAFE_SIGNALS {
2460		$vix_result = VMRunProgramInGuest($vix_vm_handle,
2461		'C:\WINDOWS\System32\taskkill.exe',
2462		'/F /IM ' . getVar(name => "process_name", namespace => $self->{'driver_name'}) . ' /T',
2463		0,
2464		VIX_INVALID_HANDLE);
2465		if ($vix_result != VIX_OK) {
2466		die "VIX::VMRunProgramInGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2467		}
2468		};
2469		alarm(0);
2470		}
2471		}
	2944	$self->_vixCloseApplication();
2472	2945	} elsif (scalar(@{$result->{'fingerprint'}->{'os_processes'}})) {
2473	2946	# Integrity check didn't pass, so try and perform automated malware extraction.
2474		$LOG->info("~~Process ID (" . $$ . "):~~ Attempting malware extraction.");
	2947	$LOG->info("Attempting malware extraction.");
2475	2948
2476	2949	foreach my $process (@{$result->{'fingerprint'}->{'os_processes'}}) {
…	…
2492	2965	my $temp_file = File::Temp->new();
2493	2966
2494		$LOG->info("Process ID (" . $$ . "): Extracting file (" . $process_file->{'name'} . ").");
2495		alarm($vix_call_timeout);
2496		UNSAFE_SIGNALS {
2497		$vix_result = VMCopyFileFromGuestToHost($vix_vm_handle,
2498		$process_file->{'name'},
2499		$temp_file->filename,
2500		0,
2501		VIX_INVALID_HANDLE);
2502		if ($vix_result != VIX_OK) {
2503		die "VIX::VMCopyFileFromGuestToHost() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2504		}
2505		};
2506		alarm(0);
2507
	2967	$LOG->info("Extracting file (" . $process_file->{'name'} . ").");
	2968	$self->_vixCopyFileFromGuestToHost(guest_filename => $process_file->{'name'},
	2969	host_filename => $temp_file->filename);
2508	2970	$process_file->{'file_content'}->{'data'} = encode_base64(compress(read_file($temp_file->filename, binmode => ':raw')));
2509	2971	};
2510	2972	if ($@) {
2511		$LOG->warn("~~Process ID (" . $$ . "):~~ (" . $self->{'quick_clone_vm_name'} . ") - Encountered error during file extraction. " . $@);
	2973	$LOG->warn("(" . $self->{'quick_clone_vm_name'} . ") - Encountered error during file extraction. " . $@);
2512	2974	}
2513	2975	}
…	…
2516	2978	}
2517	2979	}
2518
2519		$LOG->info("Process ID (" . $$ . "): Logging off guest OS.");
2520		# Logout from guest OS.
2521		alarm($vix_call_timeout);
2522		UNSAFE_SIGNALS {
2523		$vix_result = VMLogoutFromGuest($vix_vm_handle);
2524		if ($vix_result != VIX_OK) {
2525		die "VIX::VMLogoutFromGuest() Failed (" . $vix_result . "): " . GetErrorText($vix_result) . ".\n";
2526		}
2527		};
2528		alarm(0);
2529
	2980	# XXX: Cleanup.
	2981	# $self->_vixLogoutFromGuest();
2530	2982	};
2531	2983	if ($@) {
2532	2984	# We lost communications with the Agent; assume the worst
2533	2985	# and mark the VM as suspicious.
2534		$LOG->warn("~~Process ID (" . $$ . "):~~ (" . $self->{'quick_clone_vm_name'} . ") - Encountered Error or Lost Communication with Agent! Assuming Integrity Check: FAILED. " . $@);
	2986	$LOG->warn("(" . $self->{'quick_clone_vm_name'} . ") - Encountered Error or Lost Communication with Agent! Assuming Integrity Check: FAILED. " . $@);
2535	2987
2536	2988	$url->set_url_status(HoneyClient::Message::UrlStatus->new({status => "error"}));
…	…
2541	2993	# Figure out if there was a compromise found.
2542	2994	} elsif (scalar(@{$result->{'fingerprint'}->{'os_processes'}})) {
2543		$LOG->warn("~~Process ID (" . $$ . "):~~ (" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Integrity Check: FAILED");
	2995	$LOG->warn("(" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Integrity Check: FAILED");
2544	2996
2545	2997	# Dump the fingerprint to a file, if need be.
…	…
2552	3004
2553	3005	} else {
2554		$LOG->info("~~Process ID (" . $$ . "):~~ (" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Integrity Check: PASSED");
	3006	$LOG->info("(" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - Integrity Check: PASSED");
2555	3007
2556	3008	$url->set_url_status(HoneyClient::Message::UrlStatus->new({status => "visited"}));
2557	3009	}
2558	3010
	3011	# XXX: Cleanup.
2559	3012	# Make sure all VIX handles are released.
2560		# What do we do, when a VIX call times out.
2561		local $SIG{ALRM} = sub {
2562		# Croak on timeout.
2563		$LOG->error("Process ID (" . $$ . "): Error: VIX Timeout.");
2564		Carp::croak "Error: VIX Timeout.";
2565		};
2566		alarm($vix_call_timeout);
2567		UNSAFE_SIGNALS {
2568		$LOG->info("Process ID (" . $$ . "): Releasing VIX VM Handle.");
2569		ReleaseHandle($vix_vm_handle);
2570		$LOG->info("Process ID (" . $$ . "): Releasing VIX Host Handle.");
2571		HostDisconnect($vix_host_handle);
2572		};
2573		alarm(0);
2574
2575		$LOG->info("Process ID (" . $$ . "): Stopping Packet Capture Session on VM (" . $self->{'quick_clone_vm_name'} . ").");
	3013	# $self->_vixDisconnectVM();
	3014	# $self->_vixDisconnectHost();
	3015
	3016	$LOG->info("Stopping Packet Capture Session on VM (" . $self->{'quick_clone_vm_name'} . ").");
2576	3017	($capture_result, $self->{'_pcap_session'}) = HoneyClient::Manager::Pcap::Client->stopCapture(
2577	3018	session => $self->{'_pcap_session'},
…	…
2592	3033
2593	3034	# If defined, insert screenshot data.
2594		if (defined($~~vix_image_bytes~~) && $url->has_screenshot_id() && $url->screenshot_id()) {
2595		$url->set_screenshot_data(encode_base64(compress($~~vix_image_bytes~~)));
	3035	if (defined($self->{'_vix_image_bytes'}) && $url->has_screenshot_id() && $url->screenshot_id()) {
	3036	$url->set_screenshot_data(encode_base64(compress($self->{'_vix_image_bytes'})));
2596	3037	$action .= ".screenshot_data";
	3038	# Clear the screenshot buffer.
	3039	$self->{'_vix_image_bytes'} = undef;
2597	3040	}
2598	3041
…	…
2637	3080	my $urls_per_hour = (($#urls * 3600) / (time - $start_time));
2638	3081	$args{'job'}->set_urls_per_hour($urls_per_hour);
2639		$LOG->info("~~Process ID (" . $$ . "):~~ (" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - URLs/Hour: " . $urls_per_hour);
	3082	$LOG->info("(" . $self->{'quick_clone_vm_name'} . ") - " . $self->{'driver_name'} . " - URLs/Hour: " . $urls_per_hour);
2640	3083
2641	3084	# Add all the completed URLs back into the job. This allows other programs
…	…
2648	3091	$Data::Dumper::Terse = 0;
2649	3092	$Data::Dumper::Indent = 1;
2650		#print Dumper($args{'job'}->to_hashref) . "\n";
	3093	print Dumper($args{'job'}->to_hashref) . "\n";
2651	3094
2652	3095	$emit_result = undef;
…	…
2740	3183	user_name => $self->{'user_name'},
2741	3184	password => $self->{'password'},
	3185	_vix_host_handle => $self->{'_vix_host_handle'},
	3186	_vix_call_timeout => $self->{'_vix_call_timeout'},
	3187	_vix_host_updated_at => $self->{'_vix_host_updated_at'},
2742	3188	);
2743	3189

honeyclient/trunk/lib/HoneyClient/Manager/Firewall/Client.pm

r2200	r2288
310	310	};
311	311	if ($@) {
312		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error while receiving. " . $@);
313		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	312	$LOG->warn("Encountered a STOMP error while receiving. " . $@);
	313	$LOG->info("Retrying STOMP connection.");
314	314
315	315	$frame = undef;
…	…
360	360	};
361	361	if ($@) {
362		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error while sending. " . $@);
363		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	362	$LOG->warn("Encountered a STOMP error while sending. " . $@);
	363	$LOG->info("Retrying STOMP connection.");
364	364
365	365	if (defined($args{'stomp'}) &&

honeyclient/trunk/lib/HoneyClient/Manager/Firewall/Server.pm

r2200	r2288
302	302	};
303	303	if ($@) {
304		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error. " . $@);
305		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	304	$LOG->warn("Encountered a STOMP error. " . $@);
	305	$LOG->info("Retrying STOMP connection.");
306	306	$frame = undef;
307	307	if (defined($args{'stomp'}) &&
…	…
345	345	};
346	346	if ($@) {
347		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error. " . $@);
348		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	347	$LOG->warn("Encountered a STOMP error. " . $@);
	348	$LOG->info("Retrying STOMP connection.");
349	349	if (defined($args{'stomp'}) &&
350	350	(ref($args{'stomp'}) eq "Net::Stomp")) {
…	…
387	387	};
388	388	if ($@) {
389		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error. " . $@);
390		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	389	$LOG->warn("Encountered a STOMP error. " . $@);
	390	$LOG->info("Retrying STOMP connection.");
391	391	if (defined($args{'stomp'}) &&
392	392	(ref($args{'stomp'}) eq "Net::Stomp")) {

honeyclient/trunk/lib/HoneyClient/Manager/Pcap/Client.pm

r2186	r2288
289	289	};
290	290	if ($@) {
291		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error while receiving. " . $@);
292		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	291	$LOG->warn("Encountered a STOMP error while receiving. " . $@);
	292	$LOG->info("Retrying STOMP connection.");
293	293
294	294	$frame = undef;
…	…
339	339	};
340	340	if ($@) {
341		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error while sending. " . $@);
342		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	341	$LOG->warn("Encountered a STOMP error while sending. " . $@);
	342	$LOG->info("Retrying STOMP connection.");
343	343
344	344	if (defined($args{'stomp'}) &&

honeyclient/trunk/lib/HoneyClient/Manager/Pcap/Server.pm

r2186	r2288
301	301	};
302	302	if ($@) {
303		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error. " . $@);
304		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	303	$LOG->warn("Encountered a STOMP error. " . $@);
	304	$LOG->info("Retrying STOMP connection.");
305	305	$frame = undef;
306	306	if (defined($args{'stomp'}) &&
…	…
344	344	};
345	345	if ($@) {
346		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error. " . $@);
347		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	346	$LOG->warn("Encountered a STOMP error. " . $@);
	347	$LOG->info("Retrying STOMP connection.");
348	348	if (defined($args{'stomp'}) &&
349	349	(ref($args{'stomp'}) eq "Net::Stomp")) {
…	…
386	386	};
387	387	if ($@) {
388		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error. " . $@);
389		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	388	$LOG->warn("Encountered a STOMP error. " . $@);
	389	$LOG->info("Retrying STOMP connection.");
390	390	if (defined($args{'stomp'}) &&
391	391	(ref($args{'stomp'}) eq "Net::Stomp")) {

honeyclient/trunk/lib/HoneyClient/Manager/Worker.pm

r2200	r2288
298	298	sub _shutdown {
299	299	my $LOG = get_logger();
300		$LOG->warn("~~Process ID (" . $$ . "):~~ Received termination signal. Shutting down worker (please wait).");
	300	$LOG->warn("Received termination signal. Shutting down worker (please wait).");
301	301	exit;
302	302	};
…	…
326	326	};
327	327	if ($@) {
328		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error. " . $@);
329		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	328	$LOG->warn("Encountered a STOMP error. " . $@);
	329	$LOG->info("Retrying STOMP connection.");
330	330	$frame = undef;
331	331	if (defined($args{'stomp'}) &&
…	…
370	370	};
371	371	if ($@) {
372		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error. " . $@);
373		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	372	$LOG->warn("Encountered a STOMP error. " . $@);
	373	$LOG->info("Retrying STOMP connection.");
374	374	if (defined($args{'stomp'}) &&
375	375	(ref($args{'stomp'}) eq "Net::Stomp")) {
…	…
412	412	};
413	413	if ($@) {
414		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error. " . $@);
415		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	414	$LOG->warn("Encountered a STOMP error. " . $@);
	415	$LOG->info("Retrying STOMP connection.");
416	416	if (defined($args{'stomp'}) &&
417	417	(ref($args{'stomp'}) eq "Net::Stomp")) {
…	…
444	444	my ($class, %args) = @_;
445	445
446		$LOG->info("~~Process ID (" . $$ . "):~~ Starting worker.");
	446	$LOG->info("Starting worker.");
447	447
448	448	my $argsExist = scalar(%args);
…	…
500	500	});
501	501
502		$LOG->info("~~Process ID (" . $$ . "):~~ Waiting for more work.");
	502	$LOG->info("Waiting for more work.");
503	503	while (1) {
504	504	# Get a new job.
505	505	$frame = $stomp->receive_frame();
506		$LOG->info("~~Process ID (" . $$ . "):~~ Got more work.");
	506	$LOG->info("Got more work.");
507	507
508	508	# Decode the job.
…	…
514	514
515	515	# ACK the frame, indicating that the work has been completed.
516		$LOG->info("~~Process ID (" . $$ . "):~~ Signaling work complete.");
	516	$LOG->info("Signaling work complete.");
517	517	$stomp->ack({frame => $frame});
518	518
…	…
524	524	# Report when a fault occurs.
525	525	if ($@) {
526		$LOG->error("~~Process ID (" . $$ . "):~~ Encountered an error. Shutting down worker. " . $@);
	526	$LOG->error("Encountered an error. Shutting down worker. " . $@);
527	527	}
528	528
…	…
622	622	my ($class, %args) = @_;
623	623
624		$LOG->info("~~Process ID (" . $$ . "):~~ Starting worker.");
	624	$LOG->info("Starting worker.");
625	625
626	626	# If these parameters weren't defined, delete them
…	…
695	695	$stomp->subscribe($subscribe_args);
696	696
697		$LOG->info("~~Process ID (" . $$ . "):~~ Waiting for more work.");
	697	$LOG->info("Waiting for more work.");
698	698	while (1) {
699	699
…	…
703	703	connect_args => $connect_args,
704	704	subscribe_args => $subscribe_args);
705		$LOG->info("~~Process ID (" . $$ . "):~~ Got more work.");
	705	$LOG->info("Got more work.");
706	706
707	707	# TODO: Delete this, eventually.
…	…
723	723
724	724	# ACK the frame, indicating that the work has been completed.
725		$LOG->info("~~Process ID (" . $$ . "):~~ Signaling work complete.");
	725	$LOG->info("Signaling work complete.");
726	726	$stomp = _ack_retry(stomp => $stomp,
727	727	new_args => $new_args,
…	…
736	736	# Report when a fault occurs.
737	737	if ($@) {
738		$LOG->error("~~Process ID (" . $$ . "):~~ Encountered an error. Shutting down worker. " . $@);
	738	$LOG->error("Encountered an error. Shutting down worker. " . $@);
739	739	}
740	740

honeyclient/trunk/lib/HoneyClient/Util/EventEmitter.pm

r2243	r2288
267	267	};
268	268	if ($@) {
269		$LOG->warn("~~Process ID (" . $$ . "):~~ Encountered a STOMP error while sending. " . $@);
270		$LOG->info("~~Process ID (" . $$ . "):~~ Retrying STOMP connection.");
	269	$LOG->warn("Encountered a STOMP error while sending. " . $@);
	270	$LOG->info("Retrying STOMP connection.");
271	271
272	272	if (defined($args{'stomp'}) &&

Navigation

Changeset 2288

Legend:

Download in other formats: