classification
Title: newer() function in dep_util.py discard changes in the same second
Type: behavior Stage:
Components: Distutils Versions: Python 3.7, Python 3.6, Python 2.7
process
Status: open Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: d.amian, eric.araujo, jsjgruber, tarek
Priority: normal Keywords: patch

Created on 2011-11-17 11:23 by d.amian, last changed 2017-12-08 21:23 by jwilk.

Files
File name Uploaded Description Edit
fix_mtime.diff d.amian, 2011-11-17 11:23 review
Messages (9)
msg147794 - (view) Author: David Amian (d.amian) Date: 2011-11-17 11:23
Hi, I had a problem making deb packages with distutils and cdbs. Looking for any solution, I found Issue 11933 and saw that the newer() method has been changed, using [ST_MTIME] instead of st_mtime. This commit is to solve Issue 10148 that describes a bug when copying files with python, it depends on the filesystem.

In these changes, modification time of files are checked as a integer, discarding the millisec. It makes the issue.

For example, I've a file that is modified with an installation prefix. CDBS runs the build step and after the install step. In build step, the prefix is '/usr/local' because the prefix argument isn't supported, immediately the install step runs with prefix='/usr', so the file that contains a variable with project path modified with the prefix is not copied by distutils, it runs in a different millisec but in the same second.

Then when install my app, it crashes because the variable with project path is '/usr/local' instead of '/usr' and this variable is used in the source.

To solve this problem I made ​​some modifications on file_util.py and dep_util.py files, I revert the changes of the issue 11933, but rounding all times returned by stat() with two decimals. With that changes, distutils is not affected by the Issue 10148 and if any file is modified in the same second, but in different millisec, distutils will compare it and it wil copy the file.
msg147868 - (view) Author: Éric Araujo (eric.araujo) * (Python committer) Date: 2011-11-18 12:57
Hi David.  Thanks for reporting the issue.  I have to warn you that there is a high bar for distutils changes; due to the mass of code out there that relies on undocumented internal behavior or works around old bugs, a feature freeze is in effect and we try to be very careful with the changes we make to fix bugs.  Some things clearly qualify as bugs and can be fixed, some things are clearly new features and are redirected to the distutils2 project, some bugs can’t be fixed because everyone and every tool is used to the buggy behavior.  Here we are in a gray area between bug and feature; one can argue that the behavior is not what is expected (bug), but one can reply that the documentation just doesn’t say that filesystems with millisecond precision are supported (so it would be a new feature).

> For example, I've a file that is modified with an installation prefix.
Modified by what when?

> CDBS runs the build step and after the install step. In build step, the prefix is
> '/usr/local' because the prefix argument isn't supported, immediately the install step
> runs with prefix='/usr', so the file that contains a variable with project path
> modified with the prefix is not copied by distutils, it runs in a different millisec
> but in the same second.
I don’t understand when the file is changed.  (BTW, I read some Debian mailing lists and I had the impression that CDBS was deprecated.)
msg147871 - (view) Author: David Amian (d.amian) Date: 2011-11-18 13:53
sorry, I didn't explain well.
I've a project, in the setup.py file, I've a function called update_prefix, that updates the 'path_project' variable with prefix arguments from setup.py
If you runs setup.py with --prefix=/usr, then the file in 'projectname/projectnameconfig.py' is modified changing the 'path_project' variable from @PREFIX@+"share/projectname" to '/usr/share/projectname'.
If you runs setup.py without prefix arguments, the prefix is '/usr/local'.

Debuild which is the tool used to build debian package, in this case using CDBS, gives this output:
it first runs:
...
python setup.py build \
--build-base="/tmp/buildd/pdal2-0.3.1/./build"
running build
running build_py
creating /tmp/buildd/pdal2-0.3.1/build
creating /tmp/buildd/pdal2-0.3.1/build/lib.linux-i686-2.7
creating /tmp/buildd/pdal2-0.3.1/build/lib.linux-i686-2.7/pdal
copying pdal/utils.py -> /tmp/buildd/pdal2-0.3.1/./build/lib.linux-i686-2.7/pdal
copying pdal/pdalconfig.py -> /tmp/buildd/pdal2-0.3.1/./build/lib.linux-i686-2.7/pdal
...
then it runs:
...
cd . && \
		python setup.py install \
		--root="/tmp/buildd/pdal2-0.3.1/debian/pdal2/" \
		--install-purelib=/usr/lib/python2.7/site-packages/ \
		--prefix=/usr --no-compile -O0 --install-layout=deb 
running install
running build
running build_py
running build_scripts

It doesn't copy pdal/pdalconfig.py becouse the file in /tmp/buildd/pdal2-0.3.1/./build/lib.linux-i686-2.7/pdal have the same st_mtime in seconds than pdal/pdalconfig.py, but if you see de st_mtime, both are different in millisec and the file is different.

 File: «pdal/pdalconfig.py»
Modify: 2011-11-16 11:55:52.665727826 +0100

File: «/tmp/buildd/pdal2-0.3.1/./build/lib.linux-i686-2.7/pdal/pdalconfig.py»
Modify: 2011-11-16 11:55:52.000000000 +0100

but if you print the st_mtime of both files within newer() function you can check the file's timestamp are the same when they are really not:
ST_MTIME-source-target-1321440952-1321440952

That is cause of the issue, that I explain in the early comment, I fixed it rounding to two decimals instead of rounding to integer.
msg147874 - (view) Author: Éric Araujo (eric.araujo) * (Python committer) Date: 2011-11-18 14:30
> I've a project, in the setup.py file, I've a function called update_prefix, that updates the
> 'path_project' variable with prefix arguments from setup.py
> If you runs setup.py with --prefix=/usr, then the file in 'projectname/projectnameconfig.py' is
> modified changing the 'path_project' variable from @PREFIX@+"share/projectname" to
> '/usr/share/projectname'. If you runs setup.py without prefix arguments, the prefix is '/usr/local'.

Did you write a custom 'install' class or are you for example looking at sys.argv to decide whether to run your function?  If it’s not implemented as a distutils command, it’s not surprising that it does not integrate well.

> [...]
> That is cause of the issue, that I explain in the early comment, I fixed it rounding to two decimals
> instead of rounding to integer.

Okay.  Can you make sure that this is the source of the problem, for example by adding time.sleep(1) between build and install?
msg148057 - (view) Author: David Amian (d.amian) Date: 2011-11-21 16:29
2011/11/18 Éric Araujo <report@bugs.python.org>

>
> Éric Araujo <merwok@netwok.org> added the comment:
>
> > I've a project, in the setup.py file, I've a function called
> update_prefix, that updates the
> > 'path_project' variable with prefix arguments from setup.py
> > If you runs setup.py with --prefix=/usr, then the file in
> 'projectname/projectnameconfig.py' is
> > modified changing the 'path_project' variable from @PREFIX@+"share/projectname"
> to
> > '/usr/share/projectname'. If you runs setup.py without prefix arguments,
> the prefix is '/usr/local'.
>
> Did you write a custom 'install' class or are you for example looking at
> sys.argv to decide whether to run your function?  If it’s not implemented
> as a distutils command, it’s not surprising that it does not integrate well.
>

Really I've a function to update prefix based on sys.argv but i changed
this using a custom class command and the same issue occurs

>
> > [...]
> > That is cause of the issue, that I explain in the early comment, I fixed
> it rounding to two decimals
> > instead of rounding to integer.
>
> Okay.  Can you make sure that this is the source of the problem, for
> example by adding time.sleep(1) between build and install?
>

I puts a time.sleep(1) bewteen 'setup.py build' and 'setup.py install' and
I got these results:

*Without waiting:

$debuild -us -uc
[...]
mkdir -p debian/python-module-stampdir
cd . && \
python setup.py build \
--build-base="/tmp/pdal/pdal2-0.3.1/./build"
running build
running build_py
copying pdal/pdalconfig.py -> build/lib.linux-i686-2.7/pdal
running build_scripts
[...]
python setup.py install \
--root="/tmp/pdal/pdal2-0.3.1/debian/pdal2/" \
--install-purelib=/usr/lib/python2.7/site-packages/ \
-f --prefix=/usr
[...]
running build
running build_py
running build_scripts
[...]

$

The stats of files are:

File: «pdal/pdalconfig.py»
Modify: 2011-11-21 13:44:52.497971724 +0100

File: «build/lib.linux-i686-2.7/pdal/pdalconfig.py»
Modify: 2011-11-21 13:44:52.000000000 +0100

It doesn't copy in the install step because st_mtimes in newer() are the
same:
ST_MTIME-source- 1321879492
ST_MTIME-target- 1321879492

*Waiting a second between build and install:

$debuild -us -uc
[...]
mkdir -p debian/python-module-stampdir
cd . && \
python setup.py build \
--build-base="/tmp/pdal/pdal2-0.3.1/./build"
running build
running build_py
copying pdal/pdalconfig.py -> build/lib.linux-i686-2.7/pdal
running build_scripts
[...]
python setup.py install \
--root="/tmp/pdal/pdal2-0.3.1/debian/pdal2/" \
--install-purelib=/usr/lib/python2.7/site-packages/ \
-f --prefix=/usr
[...]
running build
running build_py
copying pdal/pdalconfig.py -> build/lib.linux-i686-2.7/pdal
running build_scripts
[...]

$

Obviously the file has been copied as st_mtimes in newer() differ by a
second
ST_MTIME-source- 1321879603
ST_MTIME-target- 1321879602

>
> ----------
>
> _______________________________________
> Python tracker <report@bugs.python.org>
> <http://bugs.python.org/issue13420>
> _______________________________________
>
msg148190 - (view) Author: Éric Araujo (eric.araujo) * (Python committer) Date: 2011-11-23 16:52
It’s a bit hard for me to isolate the distutils problem from the CDBS-specific parts (maybe because I’m tired :).  For years, sub-second resolution was not supported by distutils, and things were okay as long as the build* commands did the file creation and install* were only concerned with copying files.  Given the feature freeze, I’m very reluctant to add sub-second resolution.
msg302313 - (view) Author: Éric Araujo (eric.araujo) * (Python committer) Date: 2017-09-16 02:43
Coming back to this, I think this should be a safe change that fixes the issue without previsible downside.

Jacob, you opened a bug duplicate of this one: could you say what was the undesirable behaviour caused by the coarse resolution?

(I would change os.stat(source)[ST_MTIME] to os.stat(source).st_mtime but discard the other cosmetic changes + float('.2f' % ...)) conversions)
msg302315 - (view) Author: Éric Araujo (eric.araujo) * (Python committer) Date: 2017-09-16 03:06
For 3.6 and 3.7, we can avoid the original float resolution issue thanks to stat_result.st_mtime_ns.  Not sure if 2.7 should be changed.
msg307814 - (view) Author: Jakub Wilk (jwilk) Date: 2017-12-07 16:09
I don't remember why I needed it. Sorry!
History
Date User Action Args
2017-12-08 21:23:14jwilksetnosy: - jwilk
2017-12-07 16:09:10jwilksetnosy: tarek, jwilk, eric.araujo, jsjgruber, d.amian
messages: + msg307814
2017-09-16 03:06:07eric.araujosetmessages: + msg302315
2017-09-16 03:05:00eric.araujosetmessages: - msg302314
2017-09-16 02:46:43eric.araujosetmessages: + msg302314
2017-09-16 02:43:01eric.araujosetassignee: tarek ->
messages: + msg302313
versions: + Python 3.6, Python 3.7
2016-06-09 14:33:33jwilksetnosy: + jwilk
2016-06-09 14:09:06berker.peksaglinkissue18027 superseder
2011-11-23 16:52:31eric.araujosetmessages: + msg148190
2011-11-21 16:29:54d.amiansetmessages: + msg148057
2011-11-18 14:30:26eric.araujosetmessages: + msg147874
2011-11-18 13:53:54d.amiansetmessages: + msg147871
2011-11-18 12:57:48eric.araujosetnosy: + jsjgruber
messages: + msg147868
2011-11-17 11:23:58d.amiancreate