Bug report: make prep fails

[lcn2]

Describe the bug

The make prep command fails.

To Reproduce

Steps to reproduce the behavior (adjust steps as needed):

0. make prep

Expected behavior

The make prep command will states that all is OK and exit code 0.

Relevant Output

make_action 31 test ERROR exit code 2
One or more tests failed:

    make_action 31: make -f ./Makefile test: non-zero exit code: 2

One or more tests failed; 1 notice issued.

See test_ioccc/test_ioccc.log for more details.

make prep: ERROR: ./test_ioccc/prep.sh exit code: 31

make prep: see build.log for details

bug report attachment

We request that you PLEASE run the command:

./bug_report.sh

and attach the bug report file that ./bug_report.sh generated. The bug report file will be a filename in the same directory with a filename of the form: bug-report.YYYYMMDD.HHMMSS.txt and it will tell you the name as well.

vvvvvvvvvvvvvvvvvvvvvvvvv --- Drag the file into the area below, please!

bug-report.20240119.154518.txt

^^^^^^^^^^^^^^^^^^^^^^^^^ --- Drag the file into the area above, please!

Please provide the following information:

• Did you attach the above requested bug report file? Yes
• What is the airspeed Velocity of an Unladen Swallow? n/a, :-)

Additional context

Please add any other context about the problem here.

From test_ioccc/test_ioccc.log:

RUNNING: test_ioccc/chkentry_test.sh

test_ioccc/chkentry_test.sh -v 1 -d ./test_ioccc/test_JSON -c ./chkentry

EXIT_CODE set to: 32

FAILED: test_ioccc/chkentry_test.sh

These test(s) failed:

    test_ioccc/chkentry_test.sh non-zero exit code: 1

About to exit: 32

Running the command:

test_ioccc/chkentry_test.sh -v 1 -d ./test_ioccc/test_JSON -c ./chkentry

produces:

test_ioccc/chkentry_test.sh: debug[1]: -v: 1
test_ioccc/chkentry_test.sh: debug[1]: -D: 0
test_ioccc/chkentry_test.sh: debug[1]: -J: 0
test_ioccc/chkentry_test.sh: debug[1]: -q: false
test_ioccc/chkentry_test.sh: debug[1]: chkentry: ./chkentry
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.quote-null.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.sorted.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.min-whitespace-nonl.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.abstract-with-encoded-NUL.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.array-last.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.test-0.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.max-manifest.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.simple-1.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.good.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.simple-0.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.min-whitespace.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.min-manifest.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.test-1.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.empty-override.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: ERROR: test ./test_ioccc/test_JSON/info.json/good/info.reference.json should pass: chkentry FAIL with exit code: 1
test_ioccc/chkentry_test.sh: debug[1]: all JSON files were valid JSON; however some chkentry semantic tests failed

test_ioccc/chkentry_test.sh: Notice: chkentry semantic tests failed, see ./test_ioccc/chkentry_test.log for details
test_ioccc/chkentry_test.sh: ERROR: about to exit: 1

[xexyl]

Hmm ... looking at it. Was unwinding but I'll take a quick look. Wonder if I forgot to update the version of some files. Though I don't recall that being a semantics error problem.

[xexyl]

Or maybe it's when you changed the iocccsize version ? Let's see ..

[xexyl]

Well I know where it's happening but I don't know why or what changed. I can't look at this now but if you don't fix it maybe I can tomorrow.

Look here though:

./chkentry -v 0 -J 0 -- . ./test_ioccc/test_JSON/auth.json/bad/all.minimal.json

That fails with:

Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
Warning: fprint_count_err: stream is is not an open FILE *stream
ERROR[1]: main: JSON semantic check failed for .auth.json file: ./test_ioccc/test_JSON/auth.json/bad/all.minimal.json
ERROR[1]: main: JSON semantic check failed

so something is wrong with that function. But why? This used to work.

[xexyl]

It's this function:

    if (fd_is_ready(__func__, true, fileno(stream)) == false) {
        warn(__func__, "stream is is not an open FILE *stream");
        return;
    }

Did you change it?

UPDATE 0

Looking at it now I don't recall the details of it. Maybe you know what changed that caused this?

[lcn2]

It's this function:

    if (fd_is_ready(__func__, true, fileno(stream)) == false) {

        warn(__func__, "stream is is not an open FILE *stream");

        return;

    }

Did you change it?

UPDATE 0

Looking at it now I don't recall the details of it. Maybe you know what changed that caused this?

Not sure. Don't recognize that code fragment. What file and function is that code fragment from?

UPDATE 0a

Also it the problem with fd_is_ready() function call, or the code fragment you posted?

What does GitHub say, what the last commit that touched that code: be it the fd_is_ready() function or the code fragment you posted?

[xexyl]

It's this function:

    if (fd_is_ready(__func__, true, fileno(stream)) == false) {

        warn(__func__, "stream is is not an open FILE *stream");

        return;

    }

Did you change it?

UPDATE 0

Looking at it now I don't recall the details of it. Maybe you know what changed that caused this?

Not sure. Don't recognize that code fragment. What file and function is that code fragment from?

My apologies. I thought I had said where it's from but maybe not. Was pretty worn out at that point and crashed not long after. That code is in fprint_count_err(). The error message we get indicates, of course, that the function it calls, fd_is_ready() returned false.

UPDATE 0a

Also it the problem with fd_is_ready() function call, or the code fragment you posted?

It appear that fd_is_ready() returns false.

What does GitHub say, what the last commit that touched that code: be it the fd_is_ready() function or the code fragment you posted?

I was wondering about using git bisect. But I'm also going to use git log. In commit e307a6fbae0e25516f6e6e594631dee94b91f061 I fixed at least one problem in parse_json_stream: don't call fd_is_ready() if the FILE * is stdin. You actually added the function fd_is_ready() in commit a14e2ba98d823801dd463e6a690f183e2ff881e7. According to the log at least that function was not touched after that.

I wonder if something changed in macOS Sonoma that broke it? I know that make prep used to work in macOS. Now as far as that function, fd_is_ready(), it uses the poll(2) interface which I have never used. I have used select(2) a fair bit but never poll(2) so all that code is unfamiliar to me: at least the parts that do things with the syscall. So I don't know how to fix it.

macOS or not?

It's not macOS: it also fails in linux (in this case fedora 39). But why? Has it been touched since the addition of the function? Let's see if we can figure out how to determine that without bisect ...

Okay so something I see is that the call to fd_is_ready() is actually in two functions, not one. So will verbosity tell us which one called it? I'm not sure how much that will matter as the parameters are the same but it might lead us to find out which function called that calling function.

Well okay we do know what function called it: I forgot. It's in the warning. The function that called it is indeed fprint_count_err() but what called it? Let's see if we can figure it out .. Looks like it might be main() in chkentry.c and it uses stderr. That makes me wonder if I should add a check for stderr before calling the function like I did with stdout. Maybe stdin too but that remains to be seen. Let's see if this is possible ..

What's curious is in the comments in util.h for is_open_file_stream():

 * (MIS)FEATURE: Calling is_open_file_stream(stdin) will always return true.
 *               Calling is_open_file_stream(tty_stream) on a tty based stream
 *               will always return true.

Maybe the same should be done for fd_is_ready()? Might be a cleaner approach than what I did (though maybe I did check for it there). Ah! I did add the check to that function but you. must have added the comment. Okay so let's see about adding it to fd_is_ready() ... Ah but I forgot. It doesn't have a FILE *: it has a FD. So maybe it should be added elsewhere . Of course we could check for fd == 0 || isatty(fd)) .. hmm. Let's see...

That fixes he not ready problem but it introduces some other problems. I'll make that a new comment.

[xexyl]

This is what happens after we take care of the fd_is_ready() problem:

debug[1]: entry_dir is NULL
debug[1]: info_filename is .
debug[1]: auth_filename: ./test_ioccc/test_JSON/auth.json/bad/all.minimal.json
debug[5]: fread returned: 2 normal EOF reading stream at: 2 bytes
debug[1]: successful parse of JSON in .auth.json file: ./test_ioccc/test_JSON/auth.json/bad/all.minimal.json
debug[5]: about to perform JSON semantic check for .auth.json file: ./test_ioccc/test_JSON/auth.json/bad/all.minimal.json
What follows are semantic errors for .auth.json file: ./test_ioccc/test_JSON/auth.json/bad/all.minimal.json
.auth.json count error node type JTYPE_NUMBER parse tree depth 5: found 0 < minimum: 1 
.auth.json count error node type JTYPE_STRING parse tree depth 5: found 0 < minimum: 16 
.auth.json count error node type JTYPE_BOOL parse tree depth 5: found 0 < minimum: 2 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: affiliation: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: author_handle: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: author_number: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: default_handle: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: email: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: github: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: location_code: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: location_name: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: mastodon: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: name: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: past_winner: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: url: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 4 member name: alt_url: found 0 < minimum: 1 
.auth.json count error node type JTYPE_OBJECT parse tree depth 3: found 0 < minimum: 1 
.auth.json count error node type JTYPE_NUMBER parse tree depth 2: found 0 < minimum: 6 
.auth.json count error node type JTYPE_STRING parse tree depth 2: found 0 < minimum: 28 
.auth.json count error node type JTYPE_BOOL parse tree depth 2: found 0 < minimum: 1 
.auth.json count error node type JTYPE_ARRAY parse tree depth 2: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: IOCCC_auth_version: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: IOCCC_contest: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: IOCCC_contest_id: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: IOCCC_year: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: author_count: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: authors: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: chkentry_version: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: entry_num: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: fnamchk_version: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: formed_UTC: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: formed_timestamp: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: formed_timestamp_usec: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: min_timestamp: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: mkiocccentry_version: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: no_comment: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: tarball: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: test_mode: found 0 < minimum: 1 
.auth.json count error node type JTYPE_MEMBER parse tree depth 1 member name: timestamp_epoch: found 0 < minimum: 1 
debug[1]: count errors for .auth.json: 39
debug[1]: count errors for both files: 39
debug[1]: total semantic errors for .auth.json: 39
debug[1]: total semantic errors for both files: 39
ERROR[1]: main: JSON semantic check failed for .auth.json file: ./test_ioccc/test_JSON/auth.json/bad/all.minimal.json
ERROR[1]: main: JSON semantic check failed

I don't understand this! Did the file get corrupt somehow? I mean the contents. It is valid json but not valid content? Or did the semantics tables get messed up / not updated for some reason? But I don't remember how to do the latter.

Hmm .. wait. The error messages do suggest that the values are not found I think? Check this out. The file is:

{}

which has none of the contents it suggests it should have. But is that true? It was last updated 31 December of 2022: and we know this problem happened after that. According to git blame you added the contents. Is the test script messed up? But if it is why'd did it work before? Which script is wrong? The last time the chkentry_test.sh script was updated was on 5 Feb 2023.

Well I can at least apply the fix to the fd_is_ready() function. Not sure if I should check for fd == 0 though as what if someone messes with the FD numbers? Then again that's not necessary since isatty(0) will return 1 anyway. So no need to check for fd == 0, just isatty(fd) and if that's the case return true. I'll do that at least.

[xexyl]

Hmm .. that still doesn't do it when running chkentry_test.sh. Okay but that's obvious now I think on it. I'm tired apparently! Of course it's not to do with being isatty() (well in some cases anyway). We're talking about regular files! *sigh*. This is a mess and I don't know what happened.

[xexyl]

Try

./chkentry -v 9 -J 0 -- ./test_ioccc/test_JSON/info.json/bad/info.rule_2a_mismatch.wrong_type.json .

and look what happens. Could it have happened when you updated the versions of the tools maybe?

[xexyl]

Aha! That was indeed it. You forgot to update the version in the JSON files! Fixing that with sgit(1) and it works! I thought of that earlier and wish I had tried it earlier .... well I'll do a commit and then you can confirm it and hopefully can close this. Mind you I did not yet do a make prep but running the script directly works now.

[xexyl]

Aha! That was indeed it. You forgot to update the version in the JSON files! Fixing that with sgit(1) and it works! I thought of that earlier and wish I had tried it earlier .... well I'll do a commit and then you can confirm it and hopefully can close this. Mind you I did not yet do a make prep but running the script directly works now.

Not so fast. The chkentry_test.sh works now but the direct command does not ? Well anyway the version should be updated so I'll commit that at least.

[xexyl]

Aha! That was indeed it. You forgot to update the version in the JSON files! Fixing that with sgit(1) and it works! I thought of that earlier and wish I had tried it earlier .... well I'll do a commit and then you can confirm it and hopefully can close this. Mind you I did not yet do a make prep but running the script directly works now.

Not so fast. The chkentry_test.sh works now but the direct command does not ? Well anyway the version should be updated so I'll commit that at least.

Oh wait .. that was in the bad/ subdirectory so it should fail. Trying make prep to verify.

[xexyl]

ALL GOOD! I'll commit shortly.

[xexyl]

Fixed in https://github.com/ioccc-src/mkiocccentry/pull/853/commits/deb2ec8caf53061ff71e60e7716e89fdbce36ee6.

[xexyl]

Now I can continue work at the other repo though I'm not sure if I'll be doing that right now .. hard night. Hope I can rest again. Doubt it but I'm hoping I can. Well anyway I certainly won't be as productive as yesterday even if I didn't have to go out today.