[c++] [hwmon] std::ifstream read file with timeout so long

[c++] [hwmon] std::ifstream read file with timeout so long

[Nguyen Chanh]

[-- Attachment #1.1: Type: text/plain, Size: 910 bytes --]

In https://github.com/openbmc/phosphor-hwmon => hwmonio.cpp , I saw we use
the std::ifstream to open and read a device sensor.

But, I met an issue with it. In case the sensor was disabled (Ex: the Fan
was unplugged), the std::ifstream read will take a long time . The timeout
in there is so long. It makes my system have a BIG delay in each checking
sensor.

Other observation : In case the sensor device is ready, the time for sensor
reading is expected.

Measuring std::ifstream reading:

In case unplugged sensor: 91385 microseconds
In case plugged sensor. : 507 microseconds

The patch to measure the std::ifstream reading, please see attachment !

Unexpected behavior you saw

The timeout in there is so long

Expected behavior

Do we have any better solution in this case? take less more timeout.
[image: Screen Shot 2020-10-03 at 11.32.36 AM.png]
-- 
*Nguyen Minh Chanh *
*Embedded Software Engineer *

[-- Attachment #1.2: Type: text/html, Size: 4029 bytes --]

[-- Attachment #2: Screen Shot 2020-10-03 at 11.32.36 AM.png --]
[-- Type: image/png, Size: 113566 bytes --]

Re: [c++] [hwmon] std::ifstream read file with timeout so long

[Patrick Williams]

[-- Attachment #1: Type: text/plain, Size: 1251 bytes --]

On Tue, Oct 06, 2020 at 10:42:18PM +0700, Nguyen Chanh wrote:
> In https://github.com/openbmc/phosphor-hwmon => hwmonio.cpp , I saw we use
> the std::ifstream to open and read a device sensor.
> 
> But, I met an issue with it. In case the sensor was disabled (Ex: the Fan
> was unplugged), the std::ifstream read will take a long time . The timeout
> in there is so long. It makes my system have a BIG delay in each checking
> sensor.
> 
> Other observation : In case the sensor device is ready, the time for sensor
> reading is expected.
> 
> Measuring std::ifstream reading:
> 
> In case unplugged sensor: 91385 microseconds
> In case plugged sensor. : 507 microseconds

Do you know which device driver it is interacting with?  This sounds
like an issue with the underlying driver.  Perhaps it is attempting
too many retries.

> 
> The patch to measure the std::ifstream reading, please see attachment !
> 
> Unexpected behavior you saw
> 
> The timeout in there is so long
> 
> Expected behavior
> 
> Do we have any better solution in this case? take less more timeout.
> [image: Screen Shot 2020-10-03 at 11.32.36 AM.png]
> -- 
> *Nguyen Minh Chanh *
> *Embedded Software Engineer *



-- 
Patrick Williams

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: [c++] [hwmon] std::ifstream read file with timeout so long

[Anton Kachalov]

[-- Attachment #1: Type: text/plain, Size: 2746 bytes --]

Try to strace the process. Either attach strace or modify service file to
run the strace from the beginning.

To attach simply (replace $HWMON_PID with appropriate pid):

# strace -fv -tt -etrace=file -p $HWMON_PID -s 2048 -o /tmp/hwmon.log.$$

You should include "strace" package in the image by either modifying the
build/conf/local.conf and place / append the variable:
======= cut =======
IMAGE_INSTALL_append = " strace"
======= cut =======

Please note the space before the package name. It is required.

To modify service file, simply edit either source file:

https://github.com/openbmc/meta-phosphor/blob/a87fb2d1eb682ed0f04e0f269966b9ae4aafbb1e/recipes-phosphor/sensors/phosphor-hwmon/xyz.openbmc_project.Hwmon%40.service

in your local build tree or edit service file after booting the image using
"vi":

# vi /lib/systemd/system/xyz.openbmc_project.Hwmon\@.service

and change ExecStart param to:
======== cut ========
ExecParam=/usr/bin/strace -tt -etrace=file -fv -s 2048 -o /tmp/hwmon.log.$$
/usr/bin/phosphor-hwmon-readd -o %I
======== cut ========

Then reload systemd and restart the service:

# systemctl daemon-reload
# systemctl restart xyz.openbmc_project.Hwmon\@.service

And then check the /tmp/hwmon.log.* file.
With the "-tt" option you will get a precise timestamp between each syscall.

If there is nothing suspicious, try to remove the "-etrace=file" option.

On Wed, 7 Oct 2020 at 17:25, Patrick Williams <patrick@stwcx.xyz> wrote:

> On Tue, Oct 06, 2020 at 10:42:18PM +0700, Nguyen Chanh wrote:
> > In https://github.com/openbmc/phosphor-hwmon => hwmonio.cpp , I saw we
> use
> > the std::ifstream to open and read a device sensor.
> >
> > But, I met an issue with it. In case the sensor was disabled (Ex: the Fan
> > was unplugged), the std::ifstream read will take a long time . The
> timeout
> > in there is so long. It makes my system have a BIG delay in each checking
> > sensor.
> >
> > Other observation : In case the sensor device is ready, the time for
> sensor
> > reading is expected.
> >
> > Measuring std::ifstream reading:
> >
> > In case unplugged sensor: 91385 microseconds
> > In case plugged sensor. : 507 microseconds
>
> Do you know which device driver it is interacting with?  This sounds
> like an issue with the underlying driver.  Perhaps it is attempting
> too many retries.
>
> >
> > The patch to measure the std::ifstream reading, please see attachment !
> >
> > Unexpected behavior you saw
> >
> > The timeout in there is so long
> >
> > Expected behavior
> >
> > Do we have any better solution in this case? take less more timeout.
> > [image: Screen Shot 2020-10-03 at 11.32.36 AM.png]
> > --
> > *Nguyen Minh Chanh *
> > *Embedded Software Engineer *
>
>
>
> --
> Patrick Williams
>

[-- Attachment #2: Type: text/html, Size: 4001 bytes --]