Bug 9333

The Wind River build cluster has seen this specific failure once but the man package is failing many times a day with a different signature. Robert will be interested so I've CCed him.

I've looked at the error log from the autobuilder and ran some tests and looked closely at the Makefiles in the man-1.6g source code.

The msg.c file from the failed build is identical to the source from a good build, so that's not direct cause. The key error message is actually the second one ("error: expected expression at end of input") which means the compiler didn't see the closing '}' at the end of the file. For example, if I truncate the file after line 89, I get this:

 | msg.c:89:11: error: expected expression at end of input
 |  /* 69 */  "failed to fork off the command _%s_\n",

Now, if I also delete the closing quote and comma on line 69, I get this:

 |  /* 69 */  "failed to fork off the command _%s_\n
 |            ^
 | msg.c:89:11: error: missing terminating " character
 | msg.c:89:11: error: expected expression at end of input

Which matches the AB output. However, in the AB case, the full line (with closing quote) was printed as part of the error message, which adds to the confusion.

On further inspection of the Makefile in the src subdir, I see that msg.c is actually a derived file, generated by the 'makemsg' command and not part of the source package. Aha!

My first thought was a race condition between the creation of msg.c and make wanting to build msg.o. For instance, makemsg started generating msg.c and another make job waiting to compile msg.c sees the partial msg.c and starts the compiler, which since it's just a partial file hits an end-of-file after the initial " in line 89 - bingo error. By the time the error reporting output is generated, the full line is in the file and by the time the build completes, of course, the complete generated msg.c is present and intact. If this were the actual cause, it should be possible to fix by adding a serializing stamp file after the makemsg command and tell msg.o to depend on that stamp file.

However, in reading up on make, I don't it works that way and that makemsg should fully complete before it starts the compile of msg.c, since it's part of the dependency tree for msg.o.

Now I don't know enough about the Linux filesystem code and how the AB is built, but seems possible, that with fast multi-core CPUs and slow storage media (e.g., NFS), it may be possible for an alternate version of my first idea to occur. That is, make completes the makemsg task but the generated file content is still buffered being written to storage when the compile job starts and reads a partial msg.c file, throws the error, by which time more (or all) of the file is committed to disk. This would certainly be intermittent and could depend on system load, storage subsystem load, if not local storage, and CPU load/availability.

If this is what is happening, a hack to fix it might be to add a short (e.g., 1 s) sleep after the makemsg command is run to allow time for all the msg.c file contents to be flushed to disk.

I agree with you entirely up to when you blame the file system.  There's the possibility that there are parallel makes running which depend on msg.c, the first one sees msg.c doesn't exist and starts to generate it with makemsg, the second one then sees a partial msg.c and tries to use the file.  This would happen if makemsg wrote directly to msg.c instead of writing to msg.c.[random] and then mv'd the file to msg.c (thus atomically creating msg.c).  It's worth checking to see if makemsg creates msg.c atomically (write to temporary file, close, rename) or not (writes directly to msg.c).

One way of examining this case would be to put a sleep in makemsg *mid generation* so it writes a partial file and then waits for a few seconds.  This should cause any races to be more obvious.

I did look at the makemsg code and it writes to the file directly, a line at a time, with fwrite() and does not use the tempfile/mv solution. We could do this with the Makefile by specifying a tempfile name as an argument for makemsg, then do the mv, and maybe even the sleep 1 in the Makefile.

I'll make a patch to do that and attach here, if someone wants to try it a few times on the AB.

I agree with Ross FWIW. I think you have the right idea of the problem but its not likely to be the filesystem. The ABs use ext4 or XFS for local storage and only use NFS for specific shared directories (DL_DIR/SSTATE_DIR) which doesn't include WORKDIR.

Often, we've seen multiple independent make executions cause many problems, not sure if that is the case here or not.

Happened again on the autobuilder: https://autobuilder.yoctoproject.org/main/builders/nightly-ppc-lsb/builds/697/steps/BuildImages/logs/stdio

Created attachment 3064 [details]
parallel make patch

I was wrong about the filesystem being a culprit (as was pointed out). It was also not a race condition between the file being generated by 'makemsg' and another make job waiting to compile the file.

The root cause is that rules with multiple targets are not parallel make safe unless special care is taken. Consider, in this case, the targets and rule:

msg.c gripedefs.h: ../msgs/mess.en makemsg
    ./makemsg ../msgs/mess.en gripedefs.h msg.c

Make actually breaks this into two rules:

msg.c: ../msgs/mess.en makemsg
    ./makemsg ../msgs/mess.en gripedefs.h msg.c

gripedefs.h: ../msgs/mess.en makemsg
    ./makemsg ../msgs/mess.en gripedefs.h msg.c

So what happens is that both these rules are run in parallel, slightly delayed from each other. After the first one completes, msg.c is present and the waiting  job to compile msg.c starts. In the meantime the rule for gripedefs.h is running in parallel, which starts overwriting msg.c so the compiler sees a partial file and throws an error.

In a sequential make build, there will be no error because both executions of makemsg will run before the compile starts.

The fix is to introduce a dummy target to force makemsg to run only once.

Merged to master and verified by Richard Purdie.

http://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/meta/recipes-extended/man?id=437841c1fc9ddcf3fd174bb352edba183f2ed63c