Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.
Bug 1431376
Summary: | "/sys$DEVPATH/device/timeout" does not expand to a path | ||
---|---|---|---|
Product: | [Fedora] Fedora | Reporter: | Harald Reindl <h.reindl> |
Component: | open-vm-tools | Assignee: | Ravindra Kumar <ravindrakumar> |
Status: | CLOSED ERRATA | QA Contact: | Fedora Extras Quality Assurance <extras-qa> |
Severity: | unspecified | Docs Contact: | |
Priority: | unspecified | ||
Version: | 27 | CC: | bugs, h.reindl, negativo17, ravindrakumar, rjones |
Target Milestone: | --- | Keywords: | Reopened |
Target Release: | --- | ||
Hardware: | Unspecified | ||
OS: | Unspecified | ||
Whiteboard: | |||
Fixed In Version: | open-vm-tools-10.2.5-2.fc28 open-vm-tools-10.2.5-2.fc26 open-vm-tools-10.2.5-2.fc27 | Doc Type: | If docs needed, set a value |
Doc Text: | Story Points: | --- | |
Clone Of: | Environment: | ||
Last Closed: | 2018-05-12 18:21:03 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
Harald Reindl
2017-03-11 20:56:30 UTC
I have no idea what you're talking about. Could you please describe the problem you think you are observing. the udev rule which is installed with the package?! Apparently the problem is that /sys$DEVPATH does not expand to a real path. The udev rules in the package are: ACTION=="add", SUBSYSTEMS=="scsi", ATTRS{vendor}=="VMware*" , ATTRS{model}=="Virtual disk*", RUN+="/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'" ACTION=="add", SUBSYSTEMS=="scsi", ATTRS{vendor}=="VMware*" , ATTRS{model}=="VMware Virtual S", RUN+="/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'" > Apparently the problem is that /sys$DEVPATH does not expand to a real path i quote myself: >> FRANKLY at that place $DEVPATH must not exist In my testing on Rawhide, I also see the logs "failed with exit code 1." but /sys/block/sda/device/timeout is getting updated as well. I made it a different value and after reboot it got updated to 180. So, it looks like udev is able to update the timeout as expected. Harald, could you please confirm if you observed the same behavior? what about all you guys building package sstart to filter your systemlogs and dmesg for the words "error", "fail" and "warn" as i do for a decade? [root@rawhide ~]# system-errors.sh Apr 6 21:15:41 rawhide systemd-udevd: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. Apr 6 21:15:41 rawhide systemd-udevd: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. Apr 6 21:15:41 rawhide systemd-udevd: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. Apr 6 21:15:41 rawhide systemd-udevd: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. Apr 6 21:15:41 rawhide systemd-udevd: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. __________________________________________________________________ [root@rawhide ~]# which system-errors.sh /usr/local/bin/system-errors.sh __________________________________________________________________ [root@rawhide ~]# cat /usr/local/bin/system-errors.sh #!/usr/bin/bash dmesg | grep -i warn dmesg | grep -i fail dmesg | grep -i error cat /var/log/messages | grep -i warn cat /var/log/messages | grep -i fail cat /var/log/messages | grep -i error [root@rawhide ~]# rpm -q open-vm-tools open-vm-tools-10.1.5-4.fc26.x86_64 (In reply to Harald Reindl from comment #6) > what about all you guys building package sstart to filter your systemlogs > and dmesg for the words "error", "fail" and "warn" as i do for a decade? Ravindra is trying sincerely to help you to fix this bug. Please be polite to him. that maybe true but i don't get "needinfo" since the guest which i am trying is a stripped down fedora with nothing else than base-os and open-vm-tools and i can see the same error messages on full featured guests with elf built package when it contains the udev rules until i remove that udev rules I'm able to see the error messages on my Fedora installation, but I'm also noticing that udev rules are taking effect. So, I'm wondering if path is the real issue here? If path is the issue then how udev rules are getting applied? I'm trying to understand if you observed the same issue or not. To be clear, my question is, did you check if /sys/block/sda/device/timeout was updated to the value in the udev rule on your Fedora despite the system error messages? looks so [root@rawhide ~]# cat /sys/block/sda/device/timeout 180 probably when you already build a ugly constrcut like "/bin/sh" extend it with 2> /dev/null but what i don't understand from the very begin is why nobody takes notice of such errors in the logiles when write that stuff because a reasonable sysadmin is scanning his logs after every reboot for "error", "warn" and "fail" which makes it annoying __________________________________ anyways, that works without spit errors in logfiles [root@buildserver:~]$ cat /etc/systemd/system/disk-timeout.service [Unit] Description=SCSI Timeouts [Service] Type=oneshot ExecStart=/usr/local/bin/disk-timeout.sh [Install] WantedBy=multi-user.target [root@buildserver:~]$ cat /usr/local/bin/disk-timeout.sh #!/usr/bin/bash for x in /sys/block/sd* do echo 180 > "$x/device/timeout" done another option would be ExecStopPost=/usr/local/bin/disk-timeout.sh in /usr/lib/systemd/system/vmtoolsd.service -ExecStopPost -ExecStartPost (In reply to Harald Reindl from comment #11) > looks so > > [root@rawhide ~]# cat /sys/block/sda/device/timeout > 180 Thanks for the info. So far it seems to be just the log spew. > probably when you already build a ugly constrcut like "/bin/sh" extend it > with 2> /dev/null Thanks for the suggestion. VMware Tools has been using $DEVPATH in udev rules for a very long time without any issues reported by any customers, please see https://kb.vmware.com/kb/1009465. I'm suspecting something has changed in udev or Linux kernel. I'd like to root cause it before applying any fixes. > but what i don't understand from the very begin is why > nobody takes notice of such errors in the logiles when write that stuff > because a reasonable sysadmin is scanning his logs after every reboot for > "error", "warn" and "fail" which makes it annoying Sorry for the inconvenience. This was a testing gap on my side. Also, the udev rule comes from open-vm-tools package and we are using it as is in Fedora. When I updated the packages in Fedora I did test that timeout was getting applied, the only thing I did not check was system logs. I will add system logs checking to my testing of the package going forward. I have made a note of your suggestion for future changes. > anyways, that works without spit errors in logfiles I think there are benefits of using udev rules over a script. udev rules do not require another service to be maintained and rules are better integrated with udev events. So, I'd like to fix the rule if possible. Harald, could you please try following rules? ACTION=="add", SUBSYSTEMS=="scsi", ENV{DEVTYPE}=="disk", ATTRS{vendor}=="VMware*" , ATTRS{model}=="Virtual disk*", RUN+="/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'" ACTION=="add", SUBSYSTEMS=="scsi", ENV{DEVTYPE}=="disk", ATTRS{vendor}=="VMware*" , ATTRS{model}=="VMware Virtual S", RUN+="/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'" This message is a reminder that Fedora 25 is nearing its end of life. Approximately 4 (four) weeks from now Fedora will stop maintaining and issuing updates for Fedora 25. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '25'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 25 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete. Fedora 25 changed to end-of-life (EOL) status on 2017-12-12. Fedora 25 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed. please try it out yourself - the F27 testing VM which is the only one not using our self-pckaged open-vm-tools still has this messages at boot and so i don't see any reason to play ping-pong between reporter and maintainer at all Hi Ravindra Made my account here just for this: At our company we ran into the exact same issue on Ubuntu 16.04.3 (Kernel 4.4.0-116). I tested your suggested changes from Comment 15 and they worked like a charm! In the end I slightly adjusted it to better match my (Ubuntu) file (instead of ACTION=="add", I used ACTION="add|change"). I was able to easily reproduce the error in the log (starting "parted" was sufficient). Hope this helps you fix it :) Have a nice day! (Crossreference to Launchpad bug: https://bugs.launchpad.net/ubuntu/+source/open-vm-tools/+bug/1668244) even the vmware tools running on vCenter appliance 6.5 (see below) are showing the same errors but VMware does not seem to read system logs at all otherwise they would notice a ton of error in the vcenter appliance and the fact that every update breaks sendmail config https://www.reddit.com/r/vmware/comments/7mmh3o/vcenter_server_appliance_65_update_1cd_email/ _________________________________________ [root@vcenter:~]$ cat /usr/local/bin/system-erros.sh #!/bin/bash dmesg | grep -i warn dmesg | grep -i fail dmesg | grep -i error cat /var/log/messages | grep -i warn cat /var/log/messages | grep -i fail cat /var/log/messages | grep -i error _________________________________________ [root@vcenter:~]$ system-erros.sh | grep sendmail 2018-03-23T13:42:33.227130+01:00 vcenter sendmail[46836]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T13:44:22.883122+01:00 vcenter sendmail[47256]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T13:44:23.178154+01:00 vcenter sendmail[47264]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T13:50:03.174377+01:00 vcenter sendmail[48857]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T13:50:27.950703+01:00 vcenter sendmail[48943]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T14:29:43.031145+01:00 vcenter systemd[1]: sendmail.service: Unit entered failed state. 2018-03-23T14:29:43.031465+01:00 vcenter systemd[1]: sendmail.service: Failed with result 'exit-code'. 2018-03-23T14:34:49.233531+01:00 vcenter sendmail[6848]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 _________________________________________ [root@vcenter:~]$ system-erros.sh 2018-03-23T14:28:50.633977+01:00 vcenter cloud-init[850]: 2018-03-23 14:28:50,633 - util.py[WARNING]: Unable to change the ownership of /var/log/cloud-init.log to user syslog, group adm 2018-03-23T14:28:53.055846+01:00 vcenter cloud-init[1030]: 2018-03-23 14:28:52,651 - util.py[WARNING]: Unable to change the ownership of /var/log/cloud-init.log to user syslog, group adm 2018-03-23T14:28:56.189530+01:00 vcenter cloud-init[1170]: 2018-03-23 14:28:56,189 - templater.py[WARNING]: Cheetah not available as the default renderer for unknown template, reverting to the basic renderer. 2018-03-23T14:28:56.190478+01:00 vcenter cloud-init[1170]: 2018-03-23 14:28:56,190 - cc_final_message.py[WARNING]: Used fallback datasource 2018-03-23T13:42:33.227130+01:00 vcenter sendmail[46836]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T13:44:22.883122+01:00 vcenter sendmail[47256]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T13:44:23.178154+01:00 vcenter sendmail[47264]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T13:50:03.174377+01:00 vcenter sendmail[48857]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T13:50:27.950703+01:00 vcenter sendmail[48943]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T14:22:20.659137+01:00 vcenter vami-lighttp[57796]: Error: Failed to open the store. 2018-03-23T14:22:20.659946+01:00 vcenter vami-lighttp[57796]: vecs-cli failed. Error 1021: Cannot connect to vmafd service. 2018-03-23T14:22:20.661925+01:00 vcenter vami-lighttp[57796]: Failed to retrieve certificate from VECS 2018-03-23T14:22:43.221466+01:00 vcenter useradd[57983]: failed adding user 'imagebuilder', data deleted 2018-03-23T14:22:43.222897+01:00 vcenter imagebuilder: failed to add user imagebuilder 2018-03-23T14:22:44.044253+01:00 vcenter useradd[57998]: failed adding user 'netdumper', data deleted 2018-03-23T14:22:44.576376+01:00 vcenter useradd[58040]: failed adding user 'cm', data deleted 2018-03-23T14:22:45.887034+01:00 vcenter useradd[58053]: failed adding user 'deploy', data deleted 2018-03-23T14:28:48.573080+01:00 vcenter systemd-udevd[396]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573086+01:00 vcenter systemd-udevd[397]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573091+01:00 vcenter systemd-udevd[402]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573096+01:00 vcenter systemd-udevd[395]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573100+01:00 vcenter systemd-udevd[394]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573105+01:00 vcenter systemd-udevd[398]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573113+01:00 vcenter systemd-udevd[400]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573119+01:00 vcenter systemd-udevd[399]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573124+01:00 vcenter systemd-udevd[391]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573128+01:00 vcenter systemd-udevd[401]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573133+01:00 vcenter systemd-udevd[403]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573140+01:00 vcenter systemd-udevd[404]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573149+01:00 vcenter systemd-udevd[400]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573154+01:00 vcenter systemd-udevd[398]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573158+01:00 vcenter systemd-udevd[394]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573224+01:00 vcenter systemd-udevd[395]: Process '/bin/sh -c 'echo 180 >/sys$DEVPATH/device/timeout'' failed with exit code 1. 2018-03-23T14:28:48.573798+01:00 vcenter augenrules[813]: failure 1 2018-03-23T14:28:52.510204+01:00 vcenter systemd[1]: xinetd.service: Failed to read PID from file /var/run/xinetd.pid: Invalid argument 2018-03-23T14:29:43.031145+01:00 vcenter systemd[1]: sendmail.service: Unit entered failed state. 2018-03-23T14:29:43.031465+01:00 vcenter systemd[1]: sendmail.service: Failed with result 'exit-code'. 2018-03-23T14:29:51.145183+01:00 vcenter vmware-stsd[1630]: Starting vmware-stsd. Request for http://localhost:7080/afd failed after 1 seconds. Status: /usr/bin/curl status. Response: 000. Host: . Request for http://localhost:7080/afd failed after 1 seconds. Status: /usr/bin/curl status. Response: 000. Host: . Request for http://localhost:7080/afd failed after 1 seconds. Status: /usr/bin/curl status. Response: 000. Host: Increasing the timeout window to 2 seconds.. Request for http://localhost:7080/afd failed after 2 seconds. Status: /usr/bin/curl status. Response: 000. Host: Increasing the timeout window to 3 seconds.. Request for http://localhost:7080/afd failed after 3 seconds. Status: /usr/bin/curl status. Response: 000. Host: Increasing the timeout window to 4 seconds.. Request for http://localhost:7080/afd failed after 4 seconds. Status: /usr/bin/curl status. Response: 000. Host: Increasing the timeout window to 5 seconds.. Request for http://localhost:7080/afd failed after 5 seconds. Status: /usr/bin/curl status. Response: 000. Host: Increasing the timeout window to 6 seconds.. Request for http://localhost:7080/afd failed after 6 seconds. Status: /usr/bin/curl status. Response: 000. Host: Increasing the timeout window to 7 seconds.........done 2018-03-23T14:34:49.233531+01:00 vcenter sendmail[6848]: STARTTLS=client, relay=[10.0.0.15], version=TLSv1.2, verify=FAIL, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256/256 2018-03-23T14:21:57.070483+01:00 vcenter lsassd[1179]: 0x7f0e6614c700:Dropping 0 events after 225907 send attempts due to error 67 while trying to talk to the eventlog. 2018-03-23T14:22:20.659137+01:00 vcenter vami-lighttp[57796]: Error: Failed to open the store. 2018-03-23T14:22:20.659946+01:00 vcenter vami-lighttp[57796]: vecs-cli failed. Error 1021: Cannot connect to vmafd service. 2018-03-23T14:28:48.573244+01:00 vcenter systemd-udevd[396]: error opening ATTR{/sys/devices/system/cpu/cpu0/online} for writing: Permission denied 2018-03-23T14:28:48.573778+01:00 vcenter augenrules[813]: Error sending add rule data request (Rule exists) 2018-03-23T14:28:48.573783+01:00 vcenter augenrules[813]: There was an error in line 91 of /etc/audit/audit.rules raise CannotListenError(self.interface, self.port, le) CannotListenError: Couldn't listen on ::1:8201: [Errno 99] Cannot assign requested address. It got closed automatically due to EOL status of Fedora 25. Re-opening it because it is not fixed yet. Thanks Harald and Patrick. A patch for this will be released in next update of open-vm-tools. Unfortunately, a modified version of my proposed changes in #15 was included in open-vm-tools 10.2.0, but that did not fix it. open-vm-tools-10.2.5-2.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-c97904a30a open-vm-tools-10.2.5-2.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2018-7ea12a5bc4 open-vm-tools-10.2.5-2.fc26 has been submitted as an update to Fedora 26. https://bodhi.fedoraproject.org/updates/FEDORA-2018-082f8985de open-vm-tools-10.2.5-2.fc27 has been pushed to the Fedora 27 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-7ea12a5bc4 open-vm-tools-10.2.5-2.fc26 has been pushed to the Fedora 26 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-082f8985de open-vm-tools-10.2.5-2.fc28 has been pushed to the Fedora 28 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-c97904a30a open-vm-tools-10.2.5-2.fc28 has been pushed to the Fedora 28 stable repository. If problems still persist, please make note of it in this bug report. open-vm-tools-10.2.5-2.fc26 has been pushed to the Fedora 26 stable repository. If problems still persist, please make note of it in this bug report. open-vm-tools-10.2.5-2.fc27 has been pushed to the Fedora 27 stable repository. If problems still persist, please make note of it in this bug report. |