13186 2019-02-18 11:14:58 +0000 Precompiled python3 bytecode is stale 2019-11-07 16:19:59 +0000 1 1 7 Build System, Metadata & Runtime OE-Core devtools / tool chain unspecified Other Multiple RESOLVED FIXED Medium normal 3.1 1 t liezhi.yang alejandro.delcastillo alex.kanavin leon meta.mr.watcher meta.watcher randy.macleod richard.purdie ross.burton --- --- No (bug/feature does not impact docs) oldest_to_newest 83034 0 t 2019-02-18 11:14:58 +0000 With both "sumo" 3.5.5 (97ee1f80870745bf6c542ee2f184c9e468672714) and "master" 3.7.2 (c92e780c85523fe860602b947b029d7782afa47a) python3 recipes the generated .pyc files are stale. This issue can be observed best using a "readonly" rfs and starting the python3 interpreter with -vv such as 'python3 -vv -c ""'. Many messages like "bytecode is stale for 'site'" should appear indicating that the timestamp in the header of the .pyc files differs from the mtime of the corresponding .py file. For a possible solution, python's 3.7 newly introduced hash-based (CHECKED_HASH) or even (UNCHECKED_HASH) invalidation mode could also be used. Remark: Reading out the mtime from a .pyc file is described at https://qiita.com/amedama/items/698a7c4dbdd34b03b427 whereas python 3.7 has an additional 4-byte value between "magic_str" and "mtime_str" as described in https://www.python.org/dev/peps/pep-0552/. 83037 1 4434 t 2019-02-19 08:23:09 +0000 Created attachment 4434 Proposed patch for creation of data.tar 83038 2 t 2019-02-19 08:25:42 +0000 With the kind help of Richard Purdie, it was possible to pinpoint the exact cause of the .py files timestamps being altered: http://git.yoctoproject.org/cgit.cgi/opkg-utils/commit/?id=682f8c5e35b8854a9bb858b8ee1714d27e0c00db The issue is that upon creation of data.tar.$cext, the flags --mtime is used which alters the mtime of every file in it. I have tested the attached patch successfully on my embedded system. The python3 interpreter startup time is significantly faster and "-vv" does not show any stale .pyc's. 83040 3 alejandro.delcastillo 2019-02-19 19:46:01 +0000 Sent patch to opkg mailing list [1] and to OE mailing list [2] [1] https://groups.google.com/forum/#!topic/opkg-devel/fGbjrKXbOG4 [2] http://lists.openembedded.org/pipermail/openembedded-core/2019-February/279217.html 83063 4 richard.purdie 2019-02-21 15:43:16 +0000 The fix was merged into master: http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=a79bc39033c07e5cb0aa5ca95afe8f035c403f33 (thanks Alejandro) I'd really like to have a test case for this to close the issue out, would you be able to help with that? 83067 5 alex.kanavin 2019-02-21 15:58:20 +0000 Just to get you started with the test, this is the right place for it: https://git.yoctoproject.org/cgit/cgit.cgi/poky/tree/meta/lib/oeqa/runtime/cases/python.py The existing test gives a good example of how to run python and check the output. (I guess checking for absence of certain strings would be right). 83069 6 alex.kanavin 2019-02-21 16:08:36 +0000 On second thought, this might not be the right place. By the time the test would be run (on a read-write filesystem), python might have already rebuilt all the .pyc files (with dnf tests running ahead of python tests in particular). So not sure how to test this, really. There is a test for read-only images in meta/lib/oeqa/selftest/cases/buildoptions.py, but it only tests that the image builds, and won't boot it (but could be extended for that). 83108 7 t 2019-02-25 09:33:54 +0000 I have written a working test for this (for .ipk's only at the moment). The test itself is located in do_package_write_ipk_append. This solution works for my build process and if you deem it worthy for merging it into the master, feel free to do it :). 83109 8 4445 t 2019-02-25 09:34:49 +0000 Created attachment 4445 Test .pyc for stale 83110 9 alex.kanavin 2019-02-25 11:06:06 +0000 You can place this into insane.bbclass, then it will work for all package types as part of package_qa() task, and for all packages that contain .py/.pyc. 83116 10 t 2019-02-25 20:56:06 +0000 As of now the test is done by taking a .py file which is believed to be in every python3 installation "__future.py__". The test would have to be adopted to e.g. take the first .pyc it finds and the corresponding .py file or even to the test all .pyc files. Also it would have to be ideally able to extract any package format the build process may generate: ipk, deb, rpm and possibly tar. Whereas for extracting rpm files "rpm2cpio" and "cpio" or similar tools are required, which (I guess) would result in a such dependency of every recipe using the insane.bbclass. Is this really what we want? Might it be better to split this up into two tests?: - QA: Test if .pyc files in PKGDEST are not stale (this should be doable without special tools) - ??: Test if package manager's are packing files using undesired options such as --mtime. 83220 11 leon 2019-03-08 22:50:46 +0000 sumo yocto-2.5.2-127-gd3ad243 (d3ad2438222050faf33e83598c1f6ecd25ff65b6) with .deb packages, I am getting stale .pyc on my read-only target filesystem. I am using reproducible builds, and the .py files have timestamp 0 seconds since epoch, whereas the 4 byte timestamp (at byte offset 4) in each .pyc file are substantially larger. By erasing the timestamp in a .pyc file (remounting rw, dd if=/dev/zero of=some.pyc bs=1 count=4 seek=4 conv=notrunc) the .pyc file is no longer considered stale. Has this issue been fixed for all package types? 83221 12 leon 2019-03-08 23:18:58 +0000 I have debugged my case further, and the issue seems not so much in the python build itself, but in the fact that my files end up with timestamp 0 seconds since epoch on my read-only filesystem, whereas the .py files have file timestamp matching SOURCE_DATE_EPOCH=1517788422, which also matches the internal timestamp in the .pyc file. my local.conf: INHERIT += "reproducible_build" BUILD_REPRODUCIBLE_BINARIES="1" REPRODUCIBLE_TIMESTAMP_ROOTFS="1549187940" LDCONFIGDEPEND="" temp/run.do_compile.3316:83:export SOURCE_DATE_EPOCH="1517788422" this matches the last modification time of the .py file in image/ 00:06 $ ls -a --full-time image/usr/lib/python3.5/json/encoder.py -rw-r--r-- 3 leon leon 15961 2018-02-05 00:53:42.000000000 +0100 image/usr/lib/python3.5/json/encoder.py or directly printing last modification time of the file as seconds since epoch: 00:08 $ find image/usr/lib/python3.5/json/encoder.py | xargs -L1 stat -c%Y 1517788422 which in turn matches the internal timestamp in .pyc: dd if=./image/usr/lib/python3.5/json/__pycache__/encoder.cpython-35.pyc skip=4 bs=1 count=4 | od -An -tu4 4+0 records in 4+0 records out 4 bytes copied, 4.6492e-05 s, 86.0 kB/s 1517788422 However on the target the .py files are 0 seconds since epoch: root@adesys-octalarm:/usr/bin# ls --full-time -ald /usr/lib/python3.5/json/encoder.py -rw-r--r-- 3 root root 15961 1970-01-01 01:00:00.000000000 +0100 /usr/lib/python3.5/json/encoder.py 83222 13 leon 2019-03-08 23:42:34 +0000 I found that this is probably due to my filesystem being an OSTree deployment; meta-updater / meta-ostree. More info here: https://github.com/advancedtelematic/meta-updater/issues/461 84016 14 randy.macleod 2019-05-30 15:28:55 +0000 Robert, we think this has come down to needed some self-test for the consistency of the py and pyc file timestamaps. Richard can give you more guidance as needed. 85496 15 ross.burton 2019-11-07 16:19:59 +0000 Since https://www.python.org/dev/peps/pep-0552/ the cache files are invalidated based on file hashes not timestamps and the pyc files are hash based, so I believe this is resolved now. Closing. If anyone disagrees, please reopen. 4434 2019-02-19 08:23:09 +0000 2019-02-19 08:23:09 +0000 Proposed patch for creation of data.tar tar_mtime_not_for_data.patch application/octet-stream 625 t ZGlmZiAtLWdpdCBhL29wa2ctYnVpbGQgYi9vcGtnLWJ1aWxkCmluZGV4IDliMjRiOWYuLjExOTFm ZjcgMTAwNzU1Ci0tLSBhL29wa2ctYnVpbGQKKysrIGIvb3BrZy1idWlsZApAQCAtMjg5LDcgKzI4 OSw3IEBAIGVjaG8gJENPTlRST0wgPiAkdG1wX2Rpci90YXJYCiAKICMgSWdub3JlIGVycm9yIGNv ZGUgMSwgY2F1c2VkIGJ5IG1vZGlmeWluZyB0aGUgbnVtYmVyIG9mIGhhcmQgbGlua3Mgd2hpbGUg Y3JlYXRpbmcgdGhlIHRhciBmaWxlCiByYz0wCi0oIGNkICRwa2dfZGlyICYmIHRhciAkb2dhcmdz ICR0c29ydGFyZ3MgLS1tdGltZT0iJGJ1aWxkX2RhdGUiIC1YICR0bXBfZGlyL3RhclggLWMgJHRh cmZvcm1hdCAuIHwgJGNvbXByZXNzb3IgJGNvbXByZXNzb3JhcmdzID4gJHRtcF9kaXIvZGF0YS50 YXIuJGNleHQgKSB8fCByYz0kPworKCBjZCAkcGtnX2RpciAmJiB0YXIgJG9nYXJncyAkdHNvcnRh cmdzIC1YICR0bXBfZGlyL3RhclggLWMgJHRhcmZvcm1hdCAuIHwgJGNvbXByZXNzb3IgJGNvbXBy ZXNzb3JhcmdzID4gJHRtcF9kaXIvZGF0YS50YXIuJGNleHQgKSB8fCByYz0kPwogaWYgWyAkcmMg LW5lIDEgXSAmJiBbICRyYyAtbmUgMCBdOyB0aGVuCiAgICAgICAgIGV4aXQgJHJjIAogZmkKCg== 4445 2019-02-25 09:34:49 +0000 2019-11-07 15:58:00 +0000 Test .pyc for stale python3_%.bbappend text/plain 2595 t REVQRU5EUyArPSAiZHBrZy1uYXRpdmUiCmRvX3BhY2thZ2Vfd3JpdGVfaXBrW2RlcGVuZHNdICs9 ICJkcGtnLW5hdGl2ZTpkb19wb3B1bGF0ZV9zeXNyb290IgoKZG9fcGFja2FnZV93cml0ZV9pcGtf YXBwZW5kICgpIHsKICAgIGltcG9ydCBvcwogICAgaW1wb3J0IHN1YnByb2Nlc3MKCiAgICAjIElm IC5weWMgZmlsZXMgc2hhbGwgYmUgaW5jbHVkZWQgaW4gdGhlIHBhY2thZ2UsIGNoZWNrIHRoYXQg dGhlIHBhY2thZ2luZyBwcm9jZXNzIGRpZCBub3QgbWFrZSB0aGVtIHN0YWxlLgogICAgIyBUaGlz IGlzIGRvbmUgYnkgdmVyaWZ5aW5nIG9uZSAucHljIGZpbGUgaW4gdGhlIGNvcmUgcGFja2FnZSB3 aXRoIGl0cyBjb3JyZXNwb25kaW5nIC5weSBjb3VudGVycGFydC4KICAgICMgV2hlcmVhcyB0aGUg Y2hvb3NlbiBmaWxlIGlzIF9fZnV0dXJlX18gYXMgaXQgYXNzdW1lZCB0byBiZSBwYXJ0IG9mIGV2 ZXJ5IHB5dGhvbiBpbnN0YWxsYXRpb24uCiAgICBpbmNsdWRlX3B5Y3MgPSBkLmdldFZhcignSU5D TFVERV9QWUNTJykKICAgIGlmIGluY2x1ZGVfcHljcyA9PSAnMSc6CiAgICAgICAgb3V0ZGlyID0g ZC5nZXRWYXIoJ1BLR1dSSVRFRElSSVBLJykKICAgICAgICBwYWNrYWdlX2FyY2ggPSBkLmdldFZh cignUEFDS0FHRV9BUkNIJykKICAgICAgICBwdiA9IGQuZ2V0VmFyKCdQVicpCiAgICAgICAgcHIg PSBkLmdldFZhcignUFInKQogICAgICAgIGxpYmRpciA9IGQuZ2V0VmFyKCdsaWJkaXInKQogICAg ICAgIHB5dGhvbl9tYWptaW4gPSBkLmdldFZhcignUFlUSE9OX01BSk1JTicpCiAgICAgICAgcmVj aXBlX3N5c3Jvb3RfbmF0aXZlID0gZC5nZXRWYXIoJ1JFQ0lQRV9TWVNST09UX05BVElWRScpCiAg ICAgICAgYmluZGlyX25hdGl2ZSA9IGQuZ2V0VmFyKCdiaW5kaXJfbmF0aXZlJykKCiAgICAgICAg Y29yZV9pcGtnX3BhdGggPSAnezB9L3sxfScuZm9ybWF0KG91dGRpciwgcGFja2FnZV9hcmNoKQog ICAgICAgIGNvcmVfaXBrZ19maWxlID0gJ3B5dGhvbjMtY29yZV97MH0tezF9X3syfS5pcGsnLmZv cm1hdChwdiwgcHIsIHBhY2thZ2VfYXJjaCkKICAgICAgICBjb3JlX2lwa2dfZGlyID0gJ3swfS97 MX0nLmZvcm1hdChjb3JlX2lwa2dfcGF0aCwgY29yZV9pcGtnX2ZpbGUucmVwbGFjZSgnLmlwaycs ICcnKSkKICAgICAgICBweV9maWxlID0gJ3swfXsxfS9weXRob257Mn0vX19mdXR1cmVfXy5weScu Zm9ybWF0KGNvcmVfaXBrZ19kaXIsIGxpYmRpciwgcHl0aG9uX21ham1pbikKICAgICAgICBweWNf ZmlsZSA9ICd7MH17MX0vcHl0aG9uezJ9L19fcHljYWNoZV9fL19fZnV0dXJlX18uY3B5dGhvbi17 M30ucHljJy5mb3JtYXQoY29yZV9pcGtnX2RpciwgbGliZGlyLCBweXRob25fbWFqbWluLCBweXRo b25fbWFqbWluLnJlcGxhY2UoJy4nLCAnJykpCgogICAgICAgICMgRXh0cmFjdCBpcGsgZmlsZSB3 aGljaCB3YXMganVzdCBjcmVhdGVkCiAgICAgICAgaWYgb3MucGF0aC5leGlzdHMoY29yZV9pcGtn X2Rpcik6CiAgICAgICAgICAgIHNodXRpbC5ybXRyZWUoY29yZV9pcGtnX2RpcikKICAgICAgICBv cy5tYWtlZGlycyhjb3JlX2lwa2dfZGlyKQogICAgICAgIGNtZCA9ICd7MH17MX0vZHBrZyAteCB7 Mn0vezN9IHs0fScuZm9ybWF0KHJlY2lwZV9zeXNyb290X25hdGl2ZSwgYmluZGlyX25hdGl2ZSwg Y29yZV9pcGtnX3BhdGgsIGNvcmVfaXBrZ19maWxlLCBjb3JlX2lwa2dfZGlyKQogICAgICAgIHN1 YnByb2Nlc3MuY2hlY2tfb3V0cHV0KGNtZCwgc2hlbGw9VHJ1ZSwgc3RkZXJyPXN1YnByb2Nlc3Mu U1RET1VUKQoKICAgICAgICAjIERlY29kZSBoZWFkZXIgb2YgLnB5YyBmaWxlIChzZWUgaHR0cHM6 Ly93d3cucHl0aG9uLm9yZy9kZXYvcGVwcy9wZXAtMDU1Mi8pCiAgICAgICAgZGVmIGdldF9sb25n KHMpOgogICAgICAgICAgICByZXR1cm4gc1swXSArIChzWzFdIDw8IDgpICsgKHNbMl0gPDwgMTYp ICsgKHNbM10gPDwgMjQpCiAgICAgICAgd2l0aCBvcGVuKHB5Y19maWxlLCAncmInKSBhcyBmOgog ICAgICAgICAgICBtYWdpY19zdHIgPSBmLnJlYWQoNCkKICAgICAgICAgICAgYml0ZmllbGRfc3Ry ID0gZi5yZWFkKDQpCiAgICAgICAgICAgIG10aW1lX3N0ciA9IGYucmVhZCg0KQogICAgICAgICAg ICBiaXRmaWVsZCA9IGdldF9sb25nKGJpdGZpZWxkX3N0cikKICAgICAgICAgICAgcHljX2ZpbGVf bXRpbWUgPSBnZXRfbG9uZyhtdGltZV9zdHIpCiAgICAgICAgICAgIAogICAgICAgICMgUGVyZm9y bSBjaGVjayBvbmx5IHdoZW4gY2FjaGVkIGJ5dGVjb2RlIGludmFsaWRhdGlvbiBpcyBiYXNlZCBv biB0aW1lc3RhbXBzCiAgICAgICAgaWYgMCA9PSBiaXRmaWVsZDoKICAgICAgICAgICAgcHlfZmls ZV9tdGltZSA9IGludChvcy5wYXRoLmdldG10aW1lKHB5X2ZpbGUpKQogICAgICAgICAgICBpZiBw eWNfZmlsZV9tdGltZSAhPSBweV9maWxlX210aW1lOgogICAgICAgICAgICAgICAgYmIuZmF0YWwo IlBhY2thZ2VkIC5weWMgZmlsZSBfX2Z1dHVyZV9fIGlzIHN0YWxlOiBIZWFkZXIgaW4gLnB5YyBp bmRpY2F0ZXMgbXRpbWUgPSB7MH0gYnV0IC5weSBoYXMgbXRpbWUgPSB7MX0iLmZvcm1hdChweWNf ZmlsZV9tdGltZSwgcHlfZmlsZV9tdGltZSkpCn0K