cffi-wrapper-file causes unnecessary recompilation of generated lisp files

[Ilya Perminov]

I notice a problem with osicat - every time the system is loaded, wrappers.lisp (and everything that depends on it) gets recompiled. It looks like the problem is caused by a cffi bug: compile-op's input file posix/wrappers.processed-wrapper-file is generated after some compile-op's output files:

CL-USER> (asdf:input-files 'asdf:compile-op (asdf:find-component :osicat '(:posix "wrappers")))

(#P"/quicklisp/dists/quicklisp/software/osicat-20180228-git/posix/wrappers.processed-wrapper-file")

CL-USER> (asdf:output-files 'asdf:compile-op (asdf:find-component :osicat '(:posix "wrappers")))

(#P"/quicklisp/dists/quicklisp/software/osicat-20180228-git/posix/wrappers.fasl"
 #P"/quicklisp/dists/quicklisp/software/osicat-20180228-git/posix/libosicat.so"
 #P"/quicklisp/dists/quicklisp/software/osicat-20180228-git/posix/wrappers__wrapper.o")

".processed-wrapper-file", ".o", and ".so" files are all generated by the same process-op, and ".processed-wrapper-file" is generated last. As a result the input of the compile-op is newer than two of its outputs (unless everything happens within the same second).

The .o and .so files are outputs of compile-op, because of
grovel/asdf.lisp:

;;; Declare the .o and .so files as compilation outputs,
;;; so they get picked up by bundle operations.
#.(when (version<= "3.1.6" (asdf-version))
    '(defmethod output-files ((op compile-op) (c wrapper-file))
      (destructuring-bind (generated-lisp lib-file c-file o-file) (output-files 'process-op c)
        (declare (ignore generated-lisp c-file))
        (multiple-value-bind (files translatedp) (call-next-method)
          (values (append files (list lib-file o-file)) translatedp)))))

[Luís Oliveira (luismbo)]

Does this bug only affect ASDF <= 3.1.6?

[Ilya Perminov (iperminov)]

No, it only affects ASDF >= 3.1.6.

[Stelian Ionescu (sionescu)]

What ASDF version are you using ? I cant reproduce with 3.3.4.1.

[Ilya Perminov (iperminov)]

I use 3.3.2.11. I'll try upgrading, but I do not think it will make a difference. ASDF does the right thing. An up-to-date check in compute-action-stamp is (up-to-date-p (timestamp<= latest-in earliest-out)) and it has not been touched in last 3 years.
What timestamps are you getting on the generated files? In my case
ls --full-time -rt quicklisp/dists/quicklisp/software/osicat-20180228-git/posix/wrappers*
gives
 4180 2020-07-29 18:23:17.264483694 -0700 quicklisp/dists/quicklisp/software/osicat-20180228-git/posix/wrappers__wrapper.c
32400 2020-07-29 18:23:18.114473769 -0700 quicklisp/dists/quicklisp/software/osicat-20180228-git/posix/wrappers__wrapper.o
 8649 2020-07-29 18:23:18.627467780 -0700 quicklisp/dists/quicklisp/software/osicat-20180228-git/posix/wrappers.processed-wrapper-file
43710 2020-07-29 18:23:18.734466530 -0700 quicklisp/dists/quicklisp/software/osicat-20180228-git/posix/wrappers.fasl

so wrappers.processed-wrapper-file is newer than wrappers__wrapper.o and the up-to-date check in compute-action-stamp fails.

[Stelian Ionescu (sionescu)]

osicat-20180228-git is quite old too. The latest version in Quicklisp is only a few months old.

[Ilya Perminov (iperminov)]

I figured out why it is difficult to reproduce the problem: file time stamps in asdf are in seconds (universal time from FILE-WRITE-DATE), not in ms as I thought, so if process-op and compile-op happen within the same second the problem is not visible. To reproduce the problem reliably add a delay to cffi-grovel:perform just before (alexandria:copy-file ...):
grovel/asdf.lisp:
(defmethod perform ((op process-op) (c wrapper-file))
   ...
    (unwind-protect
         (progn
           (sleep 2) ; <- delay
           (alexandria:copy-file tmp-file output-file :if-to-exists :supersede))
      (delete-file tmp-file))))

I can reproduce the issue with the latest quicklisp and ASDF 3.3.4.5.

[Luís Oliveira (luismbo)]

Interesting. Thanks for the nailing down how to reproduce this. Do you have a fix in mind? You're quite welcome to send a pull request!

[Ilya Perminov (iperminov)]

An obvious fix would be to "touch" .o and .so to the correct order of file modification times, but it feels a bit hackish to me.
As this is an ASDF integration issue ASDF developers may have better ideas. I'll ask for an advice on the ASDF mailing list.

[Ilya Perminov (iperminov)]

A discussion of this bug on asdf-devel: https://mailman.common-lisp.net/pipermail/asdf-devel/2020-August/thread.html, see thread "A CFFI -ASDF integration bug".

I do not see a clean way of fixing the bug, and touching .o and .so to make them newer than .processed-wrapper-file seems to be a reasonable hack.