Bug 2035202
Summary: | vm starts network disconnected | ||
---|---|---|---|
Product: | Red Hat Enterprise Linux 8 | Reporter: | Ilkka Tengvall <ikke> |
Component: | open-vm-tools | Assignee: | Virtualization Maintenance <virt-maint> |
Status: | CLOSED DUPLICATE | QA Contact: | Virtualization Bugs <virt-bugs> |
Severity: | high | Docs Contact: | |
Priority: | unspecified | ||
Version: | 8.5 | CC: | boyang, bozhan, cavery, eterrell, jen, jsavanyo, jwolfe, ldu, leiwang, myllynen, pasik, ravindrakumar, rjones, yacao |
Target Milestone: | rc | ||
Target Release: | --- | ||
Hardware: | x86_64 | ||
OS: | Linux | ||
Whiteboard: | |||
Fixed In Version: | Doc Type: | If docs needed, set a value | |
Doc Text: | Story Points: | --- | |
Clone Of: | Environment: | ||
Last Closed: | 2022-01-04 19:03:35 UTC | Type: | Bug |
Regression: | --- | Mount Type: | --- |
Documentation: | --- | CRM: | |
Verified Versions: | Category: | --- | |
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
Cloudforms Team: | --- | Target Upstream Version: | |
Embargoed: |
Description
Ilkka Tengvall
2021-12-23 09:24:04 UTC
there is one error in logs: [root@localhost ~]# grep -i error -A5 -B5 /var/log/vmware-vmsvc-root.log [2021-12-22T15:08:29.346Z] [ message] [vmtoolsd] Plugin 'guestInfo' initialized. [2021-12-22T15:08:29.346Z] [ message] [vmtoolsd] Plugin 'powerops' initialized. [2021-12-22T15:08:29.346Z] [ message] [vmtoolsd] Plugin 'timeSync' initialized. [2021-12-22T15:08:29.346Z] [ message] [vmtoolsd] Plugin 'vmbackup' initialized. [2021-12-22T15:08:29.368Z] [ message] [powerops] Executing script: '/etc/vmware-tools/poweron-vm-default' [2021-12-22T15:08:29.466Z] [ warning] [deployPkg] DeployPkgInGuest failed, error = 5 [2021-12-22T15:08:29.478Z] [ message] [vix] VixTools_ProcessVixCommand: command 62 [2021-12-22T15:08:29.507Z] [ message] [powerops] Script exit code: 0, success = 1 [2021-12-22T15:08:59.357Z] [ warning] [vmsvc] SlashProcNet_GetRoute6: open(/proc/net/ipv6_route): No such file or directory [2021-12-22T15:08:59.357Z] [ warning] [vmsvc] RecordRoutingInfo: Unable to collect IPv6 routing table. [2021-12-22T15:09:29.354Z] [ warning] [vmsvc] SlashProcNet_GetRoute6: open(/proc/net/ipv6_route): No such file or directory -- [2021-12-23T08:43:22.053Z] [ message] [vmtoolsd] Plugin 'powerops' initialized. [2021-12-23T08:43:22.053Z] [ message] [vmtoolsd] Plugin 'timeSync' initialized. [2021-12-23T08:43:22.053Z] [ message] [vmtoolsd] Plugin 'vmbackup' initialized. [2021-12-23T08:43:22.065Z] [ message] [powerops] Executing script: '/etc/vmware-tools/poweron-vm-default' [2021-12-23T08:43:22.133Z] [ message] [vix] VixTools_ProcessVixCommand: command 62 [2021-12-23T08:43:22.139Z] [ message] [vix] ToolsDaemonTcloReceiveVixCommand: command 62, additionalError = 17 [2021-12-23T08:43:22.139Z] [ message] [powerops] Script exit code: 0, success = 1 [2021-12-23T08:43:52.066Z] [ warning] [vmsvc] SlashProcNet_GetRoute6: open(/proc/net/ipv6_route): No such file or directory [2021-12-23T08:43:52.066Z] [ warning] [vmsvc] RecordRoutingInfo: Unable to collect IPv6 routing table. [2021-12-23T08:44:22.060Z] [ warning] [vmsvc] SlashProcNet_GetRoute6: open(/proc/net/ipv6_route): No such file or directory [2021-12-23T08:44:22.061Z] [ warning] [vmsvc] RecordRoutingInfo: Unable to collect IPv6 routing table. I've also tried to add dbus requirement into vmtools service file. This came up from some github issues some years back: [Unit] Description=Service for virtual machines hosted on VMware Documentation=http://github.com/vmware/open-vm-tools ConditionVirtualization=vmware Requires=vgauthd.service After=dbus.service After=vgauthd.service DefaultDependencies=no Before=cloud-init-local.service [Service] ExecStart=/usr/bin/vmtoolsd TimeoutStopSec=5 [Install] WantedBy=multi-user.target Also=vgauthd.service I added After=dbus.service, no difference Some logs: network manager sees it disconnected too at boot: -- Unit NetworkManager-dispatcher.service has begun starting up. Dec 23 11:44:15 localhost.localdomain NetworkManager[948]: <info> [1640252655.0621] settings: Loaded settings plugin: ifcfg-rh ("/usr/lib64/NetworkManager/1.32.10-4.el8/libnm-settings-plugin-ifcfg-rh.so") Dec 23 11:44:15 localhost.localdomain NetworkManager[948]: <info> [1640252655.0622] settings: Loaded settings plugin: keyfile (internal) Dec 23 11:44:15 localhost.localdomain NetworkManager[948]: <info> [1640252655.0690] device (lo): carrier: link connected Dec 23 11:44:15 localhost.localdomain NetworkManager[948]: <info> [1640252655.0693] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1) Dec 23 11:44:15 localhost.localdomain NetworkManager[948]: <info> [1640252655.0708] manager: (net0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2) Dec 23 11:44:15 localhost.localdomain NetworkManager[948]: <info> [1640252655.0723] device (net0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external') Dec 23 11:44:15 localhost.localdomain kernel: vmxnet3 0000:0b:00.0 net0: intr type 3, mode 0, 3 vectors allocated Dec 23 11:44:15 localhost.localdomain kernel: vmxnet3 0000:0b:00.0 net0: NIC Link is Down Dec 23 11:44:15 localhost.localdomain dbus-daemon[874]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Dec 23 11:44:15 localhost.localdomain systemd[1]: Started Network Manager Script Dispatcher Service. After pressing connect in vmware, so network manager picks it up ok: -- The start-up result is done. Dec 23 11:44:56 localhost.localdomain NetworkManager[948]: <info> [1640252696.0779] device (net0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'man aged') Dec 23 11:44:56 localhost.localdomain NetworkManager[948]: <info> [1640252696.0780] device (net0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'ma naged') Dec 23 11:44:56 localhost.localdomain NetworkManager[948]: <info> [1640252696.0784] manager: NetworkManager state is now CONNECTED_LOCAL Dec 23 11:44:56 localhost.localdomain NetworkManager[948]: <info> [1640252696.0787] manager: NetworkManager state is now CONNECTED_SITE Dec 23 11:44:56 localhost.localdomain NetworkManager[948]: <info> [1640252696.0788] policy: set 'System net0' (net0) as default for IPv4 routing and DNS Dec 23 11:44:56 localhost.localdomain dbus-daemon[874]: [system] Activating via systemd: service name='org.freedesktop.resolve1' unit='dbus-org.freedesktop.resolve1.service' requested by ':1.5' (uid=0 pid=948 comm="/usr/sbin/NetworkManager --no-daemon " label="system_u:system_r:NetworkManager_t:s0") Dec 23 11:44:56 localhost.localdomain dbus-daemon[874]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.resolve1.service': Unit dbus-org.freedesktop.resolve1.service not found. Dec 23 11:44:56 localhost.localdomain NetworkManager[948]: <info> [1640252696.0846] device (net0): Activation: successful, device activated. Dec 23 11:44:56 localhost.localdomain NetworkManager[948]: <info> [1640252696.0853] manager: NetworkManager state is now CONNECTED_GLOBAL Dec 23 11:44:59 localhost.localdomain sshd[1571]: Accepted publickey for root from 10.254.254.10 port 40528 ssh2: ED25519 SHA256:VGmwHwATXldoaoEQBt9xy2oFbAcbK5gp6pQo3CdVBsI Dec 23 11:44:59 localhost.localdomain systemd[1]: Created slice User Slice of UID 0. Some errors in open-vm-tools install log: [root@localhost vmware-imc]# cat toolsDeployPkg.log [2021-12-22T15:08:29.408Z] [ debug] ## Starting deploy pkg operation [2021-12-22T15:08:29.408Z] [ debug] Deploying /var/run/92667602/imcf-ZQnNNM [2021-12-22T15:08:29.408Z] [ info] Initializing deployment module. [2021-12-22T15:08:29.408Z] [ info] Cleaning old state files. [2021-12-22T15:08:29.408Z] [ info] EXIT STATE 'INPROGRESS'. [2021-12-22T15:08:29.409Z] [ debug] Setting deploy error: 'Error removing lock '/var/log/.vmware-deploy.INPROGRESS'.(No such file or directory)'. [2021-12-22T15:08:29.409Z] [ info] EXIT STATE 'Done'. [2021-12-22T15:08:29.409Z] [ debug] Setting deploy error: 'Error removing lock '/var/log/.vmware-deploy.Done'.(No such file or directory)'. [2021-12-22T15:08:29.409Z] [ info] EXIT STATE 'ERRORED'. [2021-12-22T15:08:29.409Z] [ debug] Setting deploy error: 'Error removing lock '/var/log/.vmware-deploy.ERRORED'.(No such file or directory)'. [2021-12-22T15:08:29.409Z] [ debug] Setting deploy error: 'Success.'. [2021-12-22T15:08:29.409Z] [ info] Deploying cabinet file '/var/run/92667602/imcf-ZQnNNM'. [2021-12-22T15:08:29.409Z] [ info] Transitioning from state '(null)' to state 'INPROGRESS'. [2021-12-22T15:08:29.409Z] [ info] ENTER STATE 'INPROGRESS'. [2021-12-22T15:08:29.409Z] [ info] Reading cabinet file '/var/run/92667602/imcf-ZQnNNM' and will extract it to '/var/run/.vmware-imgcust-d1WuE8I'. [2021-12-22T15:08:29.409Z] [ info] Flags in the header: 0. [2021-12-22T15:08:29.409Z] [ info] Original deployment command: '/usr/bin/perl -I/tmp/.vmware/linux/deploy/scripts /tmp/.vmware/linux/deploy/scripts/Customize.pl /tmp/.vmware/linux/deploy/cust.cfg'. [2021-12-22T15:08:29.409Z] [ info] Actual deployment command: '/usr/bin/perl -I/var/run/.vmware-imgcust-d1WuE8I/scripts /var/run/.vmware-imgcust-d1WuE8I/scripts/Customize.pl /var/run/.vmware-imgcust-d1WuE8I/cust.cfg'. [2021-12-22T15:08:29.409Z] [ info] Extracting package files. [2021-12-22T15:08:29.446Z] [ debug] Check if cust.cfg exists. [2021-12-22T15:08:29.446Z] [ info] cust.cfg is found in '/var/run/.vmware-imgcust-d1WuE8I' directory. [2021-12-22T15:08:29.446Z] [ debug] Command to exec : '/usr/bin/cloud-init'. [2021-12-22T15:08:29.446Z] [ info] sizeof ProcessInternal is 56 [2021-12-22T15:08:29.446Z] [ info] Returning, pending output from stdout [2021-12-22T15:08:29.446Z] [ info] Returning, pending output from stderr [2021-12-22T15:08:29.447Z] [ error] execv failed to run (/usr/bin/cloud-init), errno=(2), error message:(No such file or directory) [2021-12-22T15:08:29.451Z] [ info] Process exited normally after 0 seconds, returned 127 [2021-12-22T15:08:29.451Z] [ info] No more output from stdout [2021-12-22T15:08:29.451Z] [ info] No more output from stderr [2021-12-22T15:08:29.451Z] [ info] Customization command output: ''. [2021-12-22T15:08:29.451Z] [ error] Customization command failed with exitcode: 127, stderr: ''. [2021-12-22T15:08:29.451Z] [ info] cloud-init is not installed. [2021-12-22T15:08:29.451Z] [ info] Executing traditional GOSC workflow. [2021-12-22T15:08:29.451Z] [ debug] Command to exec : '/usr/bin/perl'. [2021-12-22T15:08:29.451Z] [ info] sizeof ProcessInternal is 56 [2021-12-22T15:08:29.451Z] [ info] Returning, pending output from stdout [2021-12-22T15:08:29.451Z] [ info] Returning, pending output from stderr [2021-12-22T15:08:29.453Z] [ error] execv failed to run (/usr/bin/perl), errno=(2), error message:(No such file or directory) [2021-12-22T15:08:29.456Z] [ info] Process exited normally after 0 seconds, returned 127 [2021-12-22T15:08:29.456Z] [ info] No more output from stdout [2021-12-22T15:08:29.456Z] [ info] No more output from stderr [2021-12-22T15:08:29.456Z] [ info] Customization command output: =================== Perl script log start ================= =================== Perl script log end ================= [2021-12-22T15:08:29.456Z] [ error] Customization command failed with exitcode: 127, stderr: ''. [2021-12-22T15:08:29.456Z] [ error] Customization process returned with error. [2021-12-22T15:08:29.456Z] [ debug] Deployment result = 127. [2021-12-22T15:08:29.456Z] [ info] Setting 'unknown' error status in vmx. [2021-12-22T15:08:29.457Z] [ info] Transitioning from state 'INPROGRESS' to state 'ERRORED'. [2021-12-22T15:08:29.457Z] [ info] ENTER STATE 'ERRORED'. [2021-12-22T15:08:29.457Z] [ info] EXIT STATE 'INPROGRESS'. [2021-12-22T15:08:29.457Z] [ debug] Setting deploy error: 'Deployment failed.The forked off process returned error code.'. [2021-12-22T15:08:29.457Z] [ error] Deployment failed.The forked off process returned error code. [2021-12-22T15:08:29.457Z] [ info] Launching cleanup. [2021-12-22T15:08:29.457Z] [ debug] Command to exec : '/bin/rm'. [2021-12-22T15:08:29.457Z] [ info] sizeof ProcessInternal is 56 [2021-12-22T15:08:29.457Z] [ info] Returning, pending output from stdout [2021-12-22T15:08:29.457Z] [ info] Returning, pending output from stderr [2021-12-22T15:08:29.466Z] [ info] Process exited normally after 0 seconds, returned 0 [2021-12-22T15:08:29.466Z] [ info] No more output from stdout [2021-12-22T15:08:29.466Z] [ info] No more output from stderr [2021-12-22T15:08:29.466Z] [ info] Customization command output: ''. [2021-12-22T15:08:29.466Z] [ info] sSkipReboot: 'false', forceSkipReboot 'false'. [2021-12-22T15:08:29.466Z] [ error] Deploy error: 'Deployment failed.The forked off process returned error code.'. [2021-12-22T15:08:29.466Z] [ error] Package deploy failed in DeployPkg_DeployPackageFromFile [2021-12-22T15:08:29.466Z] [ debug] ## Closing log from the logs I see open-vm-tools tries to go for cloud-init and perl, which neither i have installed. So rpm is buggy if it lacks such dependency. If either is critical, it should require them. I try adding them into the template. Now it works. It is RPM error. If I add perl manually, the network starts to work, as the installer requires perl for initializations. So the open-vm-tools needs to be fixed with perl as dependency. Cathy/Ravindra, a couple of bugs you might want to look at related to this: https://bugzilla.redhat.com/show_bug.cgi?id=1358108 https://bugzilla.redhat.com/show_bug.cgi?id=1539802 Based on John's comment https://bugzilla.redhat.com/show_bug.cgi?id=1358108#c30 "We discussed the following on call this morning - The perl dependency comes from the deploypkg plug-in. There are three use cases for this plugin. First is to clone a template and customize guest on initial boot using vSphere’s customization feature. Second is to re-customize by SRM after a failover. Third is to re-customize the clone of a running VM using the instant clone feature. In addition, if customer is using cloud-init to do customization, then there is a dependency on python If they are using legacy customization method, then there is a dependency on perl. Not all customers use the above features, so it is undesirable to force all users of OVT to install perl. Many security sensitive customer would not want to have perl installed. We don’t see a good solution to this. Would like to close this as Won’t Fix." John has vmware's position on this issue changed? Thanks, Cathy (In reply to Cathy Avery from comment #7) > Based on John's comment > https://bugzilla.redhat.com/show_bug.cgi?id=1358108#c30 > > "We discussed the following on call this morning - The perl dependency comes > from the deploypkg plug-in. There are three use cases for this plugin. First > is to clone a template and customize guest on initial boot using vSphere’s > customization feature. Second is to re-customize by SRM after a failover. > Third is to re-customize the clone of a running VM using the instant clone > feature. In addition, if customer is using cloud-init to do customization, > then there is a dependency on python If they are using legacy customization > method, then there is a dependency on perl. Not all customers use the above > features, so it is undesirable to force all users of OVT to install perl. > Many security sensitive customer would not want to have perl installed. We > don’t see a good solution to this. Would like to close this as Won’t Fix." > > > John has vmware's position on this issue changed? > > Thanks, > > Cathy Hi Cathy, Position is the same. We don't want to force all users to install perl. Thanks, John OK so it looks like we will not be fixing this issue and we will be closing this BZ as a duplicate of 1358108. Thanks, Cathy *** This bug has been marked as a duplicate of bug 1358108 *** Hello John Savanyo , It would be perfect if these dependencies are mentioned somewhere in the otherwise long and descriptive README https://github.com/vmware/open-vm-tools/blob/master/README.md Thank you The needinfo request[s] on this closed bug have been removed as they have been unresolved for 120 days |