close streams

[skshetry]

I have been seeing weird perf issue when the output was being redirected:

$ time dvc plots show --json | less
{}
dvc plots show --json  0.38s user 0.06s system 96% cpu 0.452 total
less  0.00s user 0.00s system 0% cpu 1.731 total

$ time DVC_NO_ANALYTICS=true dvc plots show --json | less
{}
DVC_NO_ANALYTICS=true dvc plots show --json  0.33s user 0.04s system 96% cpu 0.393 total
less  0.00s user 0.00s system 0% cpu 0.393 total

I could not find an issue why it would take so long, but my suspicion was that the stdin to the less was not being closed for some reason. So I tried adding os.close() and it was fast again.

I was not able to find an issue regarding this on Cpython, and I would love if I could get confirmation of the bug from other team members as well.

The dvc doctor output is:

dvc doctor
DVC version: 2.48.1.dev1+g82fbbb33c.d20230314
---------------------------------------------
Platform: Python 3.11.0 on Linux-6.2.5-arch1-1-x86_64-with-glibc2.37
Subprojects:
        dvc_data = 0.44.1
        dvc_objects = 0.21.1
        dvc_render = 0.2.1.dev4+g31002b2
        dvc_task = 0.2.0
        scmrepo = 0.1.15
Supports:
        azure (adlfs = 2023.1.0, knack = 0.10.1, azure-identity = 1.12.0),
        gdrive (pydrive2 = 1.15.1),
        gs (gcsfs = 2023.3.0),
        hdfs (fsspec = 2023.3.0, pyarrow = 11.0.0),
        http (aiohttp = 3.8.4, aiohttp-retry = 2.8.3),
        https (aiohttp = 3.8.4, aiohttp-retry = 2.8.3),
        oss (ossfs = 2021.8.0),
        s3 (s3fs = 2023.3.0, boto3 = 1.24.59),
        ssh (sshfs = 2023.1.0),
        webdav (webdav4 = 0.9.8),
        webdavs (webdav4 = 0.9.8),
        webhdfs (fsspec = 2023.3.0)
Cache types: reflink, hardlink, symlink
Cache directory: btrfs on /dev/mapper/luks-32904e1a-5815-412d-855b-a16aaae40528
Caches: local
Remotes: https
Workspace directory: btrfs on /dev/mapper/luks-32904e1a-5815-412d-855b-a16aaae40528
Repo: dvc, git
Repo.site_cache_dir: /var/tmp/dvc/repo/217568916d1a48a014e29707a1b2dbb9

[codecov]

Codecov Report

Patch and project coverage have no change.

Comparison is base (440cb9d) 92.88% compared to head (c516a4c) 92.89%.

Additional details and impacted files

@@           Coverage Diff           @@
##             main    #9204   +/-   ##
=======================================
  Coverage   92.88%   92.89%           
=======================================
  Files         457      457           
  Lines       36938    36954   +16     
  Branches     5334     5339    +5     
=======================================
+ Hits        34311    34328   +17     
  Misses       2100     2100           
+ Partials      527      526    -1     

Impacted Files	Coverage Δ
dvc/daemon.py	42.25% <0.00%> (-0.61%)	⬇️

... and 3 files with indirect coverage changes

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

☔ View full report in Codecov by Sentry.
📢 Do you have feedback about the report comment? Let us know in this issue.

[daavoo]

I was not able to find an issue regarding this on Cpython, and I would love if I could get confirmation of the bug from other team members as well.

I can confirm:

dvc plots show --json  0,68s user 0,22s system 99% cpu 0,910 total
less  0,00s user 0,00s system 0% cpu 2,642 total

DVC_NO_ANALYTICS=true dvc plots show --json  0,65s user 0,17s system 98% cpu 0,837 total
less  0,00s user 0,01s system 0% cpu 1,131 total

[efiop]

Hm, this line fixes the problem? Usually the first 3 fds are stdin/stdout/stderr, are you sure this line is doing anything?

[skshetry]

yes, that's what surprises me. It's as if close() is not working, maybe they are not really closed until the interpreter shuts down? Idk.

[efiop]

Or maybe stdin/stdout/stderr are not really fds 0, 1, 2 Could you check?

[skshetry]

The first thing that I tried to fix this was:

sys.stdin = None
sys.stdout = None
sys.stderr = None

And it magically worked. So I thought maybe there was a garbage collection issue.
But, adding gc.collect() did not fix it. Then I went to os.close() for code clarity. :)

[skshetry]

Or maybe stdin/stdout/stderr are not really fds 0, 1, 2 Could you check?

No, they are 0, 1, and 2.

[skshetry]

Tbh i don't know what I am doing here. I am also surprised that this fixes the issue. :)

[efiop]

Looks like you are not first to run into this https://code.activestate.com/recipes/186101-really-closing-stdin-stdout-stderr/

[efiop]

So looks like sys.* is python level and doesn't necessarily close underlying filedescriptors. I guess that explains this change.

[skshetry]

hmm, I searched everywhere but could not get a hint. Thank you for the link. 🙏🏼