Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Endless loop during gen_reflection_test #12

Closed
csstup opened this issue Oct 19, 2016 · 16 comments
Closed

Endless loop during gen_reflection_test #12

csstup opened this issue Oct 19, 2016 · 16 comments
Labels

Comments

@csstup
Copy link

csstup commented Oct 19, 2016

Testing the latest master.

During the "Scanning dependencies of target gen_reflection_test" phase, process goes runaway.

root 1286372 872504 93 12:45:32 pts/0 2:19 ../../../../bin/flatcc_d --schema -o /work/stupc/flatcc-master/build/Debug/test/reflection_test/generated /work/stupc/flatcc-master/test/monster_test/monster_test.fbs

Attaching with the debugger shows that its stuck in an endless loop inside flatcc_builder_create_cached_vtable().

Stack trace:

flatcc_builder_create_cached_vtable(B = 0x2ff22140, vt = 0x20072d9a, vt_size = 12, vt_hash = 1232720082), line 1082 in "builder.c"
flatcc_builder_end_table(B = 0x2ff22140), line 1243 in "builder.c"
reflection_Field_end(B = 0x2ff22140), line 30 in "reflection_builder.h"
reflection_Field_vec_push_end(B = 0x2ff22140), line 139 in "reflection_builder.h"
export_fields(B = 0x2ff22140, ct = 0x200029d8), line 167 in "codegen_schema.c"
export_objects(B = 0x2ff22140, objects = 0x20071a78, nobjects = 11, object_map = 0x20071b08), line 188 in "codegen_schema.c"
export_schema(B = 0x2ff22140, opts = 0x200011f8, S = 0x200012d8), line 281 in "codegen_schema.c"
__flatcc_fb_codegen_bfbs_alloc_buffer(opts = 0x200011f8, S = 0x200012d8, size = 0x2ff22274), line 394 in "codegen_schema.c"
__flatcc_fb_codegen_bfbs_to_file(opts = 0x200011f8, S = 0x200012d8), line 417 in "codegen_schema.c"
flatcc_generate_files(ctx = 0x20001178), line 468 in "flatcc.c"
main(argc = 5, argv = 0x2ff225b8), line 430 in "flatcc_cli.c"

If you continue, and break again, you're still inside the same loop:

flatcc_builder_create_cached_vtable(B = 0x2ff22140, vt = 0x20072d9a, vt_size = 12, vt_hash = 1232720082), line 1080 in "builder.c"
flatcc_builder_end_table(B = 0x2ff22140), line 1243 in "builder.c"
reflection_Field_end(B = 0x2ff22140), line 30 in "reflection_builder.h"
reflection_Field_vec_push_end(B = 0x2ff22140), line 139 in "reflection_builder.h"
export_fields(B = 0x2ff22140, ct = 0x200029d8), line 167 in "codegen_schema.c"
export_objects(B = 0x2ff22140, objects = 0x20071a78, nobjects = 11, object_map = 0x20071b08), line 188 in "codegen_schema.c"
export_schema(B = 0x2ff22140, opts = 0x200011f8, S = 0x200012d8), line 281 in "codegen_schema.c"
__flatcc_fb_codegen_bfbs_alloc_buffer(opts = 0x200011f8, S = 0x200012d8, size = 0x2ff22274), line 394 in "codegen_schema.c"
__flatcc_fb_codegen_bfbs_to_file(opts = 0x200011f8, S = 0x200012d8), line 417 in "codegen_schema.c"
flatcc_generate_files(ctx = 0x20001178), line 468 in "flatcc.c"
main(argc = 5, argv = 0x2ff225b8), line 430 in "flatcc_cli.c"
@mikkelfj
Copy link
Contributor

Is this a little or big endian machine?

It may be worthwhile disabling the reflection test until other tests pass because it is a higher level test that depends on other things working, such as building flatbuffers.

mkdir -p build/noreflection
cd build/noreflection
cmake ../.. -GNinja -DCMAKE_BUILD_TYPE=Debug -DFLATCC_REFLECTION=no
ninja
ninja test
(or ditto make)

@csstup
Copy link
Author

csstup commented Oct 19, 2016

Big endian. Big endian rules. :)

I'll try to create without reflection and see what that gets me.

BTW, I dumped out the value of the next member during that while loop:

while (next) {
    printf( "next = %x\n", next);
    vd = vd_ptr(next);
    vt_ = vb_ptr(vd->vb_start);

next = 50
next = 20
next = 50
next = 20
next = 50
next = 20
next = 50
next = 20
next = 20

@mikkelfj
Copy link
Contributor

That issue inside flatcc_builder_create_cached_vtable will be hard to track down without debugger access. Two possible reasons for this issue could be incorrect initialization of variables or other state which is triggered by this particular compiler, or a different hash computation that triggers a bug not present in the current test on other machines, or incorrect assumpions during pointer cast.
(just saw you update while writing this - will have a look)

@csstup
Copy link
Author

csstup commented Oct 19, 2016

I get a clean compile now, but tests fail.

I'll dig deeper into why next.

Here's the log from the tests:

bash-4.2# gmake test
Running tests...
Test project /work/stupc/flatcc-master/build/noreflection
      Start  1: cgen_test
 1/13 Test  #1: cgen_test ........................   Passed    0.02 sec
      Start  2: monster_test
 2/13 Test  #2: monster_test .....................***Failed    0.00 sec
      Start  3: monster_test_solo
 3/13 Test  #3: monster_test_solo ................***Failed    0.00 sec
      Start  4: monster_test_concat
 4/13 Test  #4: monster_test_concat ..............***Failed    0.00 sec
      Start  5: monster_test_prefix
 5/13 Test  #5: monster_test_prefix ..............***Failed    0.00 sec
      Start  6: flatc_compat
 6/13 Test  #6: flatc_compat .....................   Passed    0.00 sec
      Start  7: test_basic_parse
 7/13 Test  #7: test_basic_parse .................   Passed    0.00 sec
      Start  8: test_json_parser
 8/13 Test  #8: test_json_parser .................***Exception: Other  0.01 sec
      Start  9: test_json_printer
 9/13 Test  #9: test_json_printer ................***Failed    0.00 sec
      Start 10: test_json
10/13 Test #10: test_json ........................***Failed    0.00 sec
      Start 11: emit_test
11/13 Test #11: emit_test ........................***Exception: Other  0.01 sec
      Start 12: load_test

12/13 Test #12: load_test ........................***Exception: Other  9.96 sec
      Start 13: monster
13/13 Test #13: monster ..........................***Exception: Other  0.02 sec

23% tests passed, 10 tests failed out of 13

Total Test time (real) =  10.17 sec

The following tests FAILED:
          2 - monster_test (Failed)
          3 - monster_test_solo (Failed)
          4 - monster_test_concat (Failed)
          5 - monster_test_prefix (Failed)
          8 - test_json_parser (OTHER_FAULT)
          9 - test_json_printer (Failed)
         10 - test_json (Failed)
         11 - emit_test (OTHER_FAULT)
         12 - load_test (OTHER_FAULT)
         13 - monster (OTHER_FAULT)
Errors while running CTest
Makefile:75: recipe for target 'test' failed
gmake: *** [test] Error 8

@mikkelfj
Copy link
Contributor

OK, this is not unexpected as flatcc hasn't yet been tested with big endian, as documented.
If you are willing to work with me on this, we should be able to get it sorted, but right now I need some sleep :)
Each test should produce a lot more output which you will get by running it directly, or with a debugger, for example:
cd build/noreflection
test/monster_test/monster_test_d

However, I suspect this particular bug may have other reasons than big endian such as non-zeroed allocation failing to terminate the hash list being traversed.

@csstup
Copy link
Author

csstup commented Oct 19, 2016

Sure, we'll work together. I've worked with other projects to get them ported to AIX and big endian before.

Get some rest, we'll approach more tomorrow.

Thanks!

@mikkelfj
Copy link
Contributor

Great thanks - I've done a lot big endian work on mobile devices in a former life.

@mikkelfj mikkelfj added the bug label Oct 20, 2016
@mikkelfj
Copy link
Contributor

mikkelfj commented Oct 20, 2016

I have pushed a fix that should solve this particular issue.

I was able to reproduce by pretending flatbuffers was a big endian format. My suspicion about changed hash value triggering a bug was correct, and the bug also applies to little endian. However, due to the multiplicative hash function, collisions are more likely on big endian, which triggered the problem. It was a simple pointer chaining mistake during a move to head hash optimization.

This, of course, does not address all the other big endian related issues, but is comforting to know that the basic reader operation seems to work, otherwise flatc_compat wouldn't pass - it reads a pregenerated flatbuffer, and it correctly fails when I pretend flatbuffers is a big endian format.

@mikkelfj
Copy link
Contributor

I also pushed a fix because vtables were only partially converted to protocol endian.
This change keeps vtables in native format in memory and only converts when writing the table. When vtables are reused this is more efficient, and it also avoids the increase in hash table collisions (Knuths multiplier prefer small values).

I use the term native endian and protocol endian, because in flatcc_types.h it is possible to change the format:
#define FLATBUFFERS_PROTOCOL_IS_LE 1
#define FLATBUFFERS_PROTOCOL_IS_BE 0

@csstup
Copy link
Author

csstup commented Oct 20, 2016

Downloaded current master. Still building without reflection. Improvement with the tests!

bash-4.2# gmake test
Running tests...
Test project /work/stupc/flatcc-master/build/noreflection
      Start  1: cgen_test
 1/13 Test  #1: cgen_test ........................   Passed    0.03 sec
      Start  2: monster_test
 2/13 Test  #2: monster_test .....................***Failed    0.01 sec
      Start  3: monster_test_solo
 3/13 Test  #3: monster_test_solo ................   Passed    0.00 sec
      Start  4: monster_test_concat
 4/13 Test  #4: monster_test_concat ..............   Passed    0.00 sec
      Start  5: monster_test_prefix
 5/13 Test  #5: monster_test_prefix ..............   Passed    0.00 sec
      Start  6: flatc_compat
 6/13 Test  #6: flatc_compat .....................   Passed    0.01 sec
      Start  7: test_basic_parse
 7/13 Test  #7: test_basic_parse .................   Passed    0.00 sec
      Start  8: test_json_parser
 8/13 Test  #8: test_json_parser .................***Exception: Other  0.01 sec
      Start  9: test_json_printer
 9/13 Test  #9: test_json_printer ................***Failed    0.01 sec
      Start 10: test_json
10/13 Test #10: test_json ........................***Exception: Other  0.01 sec
      Start 11: emit_test
11/13 Test #11: emit_test ........................   Passed    0.01 sec
      Start 12: load_test

12/13 Test #12: load_test ........................   Passed   51.48 sec
      Start 13: monster
13/13 Test #13: monster ..........................   Passed    0.02 sec

69% tests passed, 4 tests failed out of 13

Total Test time (real) =  51.71 sec

The following tests FAILED:
          2 - monster_test (Failed)
          8 - test_json_parser (OTHER_FAULT)
          9 - test_json_printer (Failed)
         10 - test_json (OTHER_FAULT)
Errors while running CTest
Makefile:75: recipe for target 'test' failed
gmake: *** [test] Error 8

Nothing hung, I'm going to dig in shortly to see why particular tests are failing. Thanks!

@csstup
Copy link
Author

csstup commented Oct 20, 2016

If you're curious, here's the output from the latest monster_test:

bash-4.2# ./monster_test_d
running debug monster test
table with empty struct:
  0000  08 00 00 00 4d 4f 4e 53  fc ff ff ff 06 00 04 00  ....MONS........
  0010  04 00                                            ..
typed table with empty struct:
  0000  08 00 00 00 b6 37 dd b0  fc ff ff ff 06 00 04 00  .....7..........
  0010  04 00                                            ..
empty monster table:
  0000  08 00 00 00 4d 4f 4e 53  e8 ff ff ff 04 00 00 00  ....MONS........
  0010  09 00 00 00 4d 79 4d 6f  6e 73 74 65 72 00 00 00  ....MyMonster...
  0020  0c 00 08 00 00 00 00 00  00 00 04 00              ............
empty typed monster table:
  0000  08 00 00 00 81 f4 0e 33  e8 ff ff ff 04 00 00 00  .......3........
  0010  09 00 00 00 4d 79 4d 6f  6e 73 74 65 72 00 00 00  ....MyMonster...
  0020  0c 00 08 00 00 00 00 00  00 00 04 00              ............
Monster not available
monster table:
  0000  0c 00 00 00 4d 4f 4e 53  00 00 00 00 d4 fd ff ff  ....MONS........
  0010  50 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  P...............
  0020  00 00 80 3f 00 00 00 40  cd cc 4c c0 00 00 00 00  ...?...@..L.....
  0030  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
  0040  90 01 00 00 02 00 00 00  78 01 00 00 5c 01 00 00  ........x...\...
  0050  f4 00 00 00 c0 00 00 00  b4 00 00 00 01 00 00 00  ................
  0060  34 01 00 00 1c 00 00 00  00 00 00 00 10 00 00 00  4...............
  0070  00 00 00 00 00 00 00 00  00 00 00 00 48 fe ff ff  ............H...
  0080  68 fe ff ff 78 00 00 00  04 00 00 00 03 00 00 00  h...x...........
  0090  4c 00 00 00 28 00 00 00  04 00 00 00 9a fe ff ff  L...(...........
  00a0  f4 00 00 00 08 00 00 00  01 00 00 00 08 00 00 00  ................
  00b0  61 6e 79 20 6e 61 6d 65  00 00 00 00 d0 fe ff ff  any name........
  00c0  01 00 00 00 d0 00 00 00  04 00 00 00 08 00 00 00  ................
  00d0  61 6e 79 20 6e 61 6d 65  00 00 00 00 f0 fe ff ff  any name........
  00e0  01 00 00 00 b0 00 00 00  04 00 00 00 08 00 00 00  ................
  00f0  61 6e 79 20 6e 61 6d 65  00 00 00 00 09 00 00 00  any name........
  0100  74 68 65 20 65 6e 65 6d  79 00 00 00 04 00 00 00  the enemy.......
  0110  00 01 01 00 03 00 00 00  20 00 00 00 14 00 00 00  ........ .......
  0120  04 00 00 00 06 00 00 00  77 6f 72 6c 64 21 00 00  ........world!..
  0130  02 00 00 00 2c 00 00 00  05 00 00 00 48 65 6c 6c  ....,.......Hell
  0140  6f 00 00 00 08 00 00 00  20 00 00 00 48 00 00 00  o....... ...H...
  0150  30 00 00 00 40 00 00 00  28 00 00 00 38 00 00 00  0...@...(...8...
  0160  08 00 00 00 1c 00 00 00  88 ff ff ff 04 00 00 00  ................
  0170  08 00 00 00 47 75 6c 6c  69 76 65 72 00 00 00 00  ....Gulliver....
  0180  a0 ff ff ff 04 00 00 00  05 00 00 00 4a 6f 6b 65  ............Joke
  0190  72 00 00 00 b4 ff ff ff  04 00 00 00 07 00 00 00  r...............
  01a0  54 77 6f 46 61 63 65 00  05 00 00 00 10 00 20 00  TwoFace....... .
  01b0  30 00 40 00 50 00 60 00  70 00 80 00 91 01 91 2c  0.@.P.`.p......,
  01c0  0a 00 00 00 00 01 02 03  04 05 06 07 08 09 00 00  ................
  01d0  09 00 00 00 4d 79 4d 6f  6e 73 74 65 72 00 00 00  ....MyMonster...
  01e0  0c 00 08 00 00 00 00 00  00 00 04 00 16 00 10 00  ................
  01f0  00 00 00 00 00 00 0c 00  00 00 00 00 00 00 04 00  ................
  0200  08 00 16 00 0d 00 00 00  00 00 00 00 08 00 00 00  ................
  0210  00 00 00 00 0c 00 04 00  1c 00 0c 00 00 00 00 00  ................
  0220  00 00 04 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
  0230  00 00 08 00 04 00 04 00  36 00 64 00 14 00 00 00  ........6.d.....
  0240  04 00 34 00 00 00 3c 00  38 00 50 00 54 00 40 00  ..4...<.8.P.T.@.
  0250  48 00 44 00 58 00 00 00  60 00 5c 00 00 00 00 00  H.D.X...`.\.....
  0260  00 00 00 00 00 00 00 00  00 00 00 00 4c 00        ............L.
SKIPPING DIRECT VECTOR ACCESS ON NON-NATIVE ENDIAN PLATFORM
dbg: struct buffer size: 48
Vec3 struct buffer:
  0000  10 00 00 00 4d 4f 4e 53  00 00 00 00 00 00 00 00  ....MONS........
  0010  3f 80 00 00 40 00 00 00  40 40 00 00 00 00 00 00  ?...@...@@......
  0020  40 10 cc cc cc cc cc cd  08 00 0a aa ef 00 00 00  @...............
struct buffer not valid
TEST FAILED

@mikkelfj
Copy link
Contributor

Thanks, this confirms what I can also see by encoding the buffer as big endian. Structs are read correctly but apparently not converted during build, at least in some cases (Vec3_t), and I also see some segfaults I have not tracked down yet.

I have more problems though, because big endian encoding triggers issues not visible on little endian encoding on big endian platforms - notably the flatbuffer identifier field - I'll get back when I get this sorted.

@csstup
Copy link
Author

csstup commented Oct 20, 2016

This might help you as well. From test_json_d:

bash-4.2# ./test_json_d
84: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":19}
94: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Blue"}
98: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":2}
102: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster"}
106: json test: printed buffer not as expected, got:
{"mana":150,"hp":100,"name":"","color":"Blue","testbool":true,"testhashs32_fnv1":0,"testhashu32_fnv1":0,"testhashs64_fnv1":0,"testhashu64_fnv1":0,"testhashs32_fnv1a":0,"testhashu32_fnv1a":0,"testhashs64_fnv1a":0,"testhashu64_fnv1a":0}
expected:
{"mana":150,"hp":100,"name":"Monster","color":"Blue","testbool":true,"testhashs32_fnv1":0,"testhashu32_fnv1":0,"testhashs64_fnv1":0,"testhashu64_fnv1":0,"testhashs32_fnv1a":0,"testhashu32_fnv1a":0,"testhashs64_fnv1a":0,"testhashu64_fnv1a":0}
110: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Blue"}
114: json test: printed buffer not as expected, got:
{"hp":0,"name":""}
expected:
{"hp":42,"name":"Monster"}
118: json test: printed buffer not as expected, got:
{hp:0,name:""}
expected:
{hp:42,name:"Monster"}
124: json test: printed buffer not as expected, got:
{"hp":0,"name":""}
expected:
{"hp":42,"name":"Monster"}
172: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"Monster"}
175: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Red"}
178: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Green"}
181: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Red Green Blue"}
184: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Red Green Blue"}
186: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Red"}
189: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Green"}
193: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"Monster"}
197: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"Monster"}
217: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Red"}
220: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Green"}
223: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Red Blue"}
226: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Red Green Blue"}
229: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":12}
232: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":15}
235: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":0}
238: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Red"}
241: json test: printed buffer not as expected, got:
{"name":"","color":0}
expected:
{"name":"Monster","color":"Red"}
244: json test: printed buffer not as expected, got:
{"hp":0,"name":""}
expected:
{"hp":2,"name":"Monster"}
247: json test: printed buffer not as expected, got:
{"hp":0,"name":""}
expected:
{"hp":2,"name":"Monster"}
250: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"Monster","test_type":"Monster","test":{"name":"any Monster"}}
254: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"Monster","test_type":"Monster","test":{"name":"second Monster"}}
258: json test: printed buffer not as expected, got:
{"hp":0,"name":"","color":0}
expected:
{"hp":17,"name":"Monster","color":"Green","test_type":"Monster","test":{"name":"second Monster"}}
262: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"Monster"}
265: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"Monster"}
278: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"Monster","test_type":"Monster","test":{"name":"second Monster","color":"Red Green"}}
293: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"Mon▒▒\u0003s▒▒øter\b\f\n\r\t\"\\/'/"}
296: json test: printed buffer not as expected, got:
{"name":""}
expected:
{"name":"ᚋᚑ"}
Assertion failed: 0 && "buffer header too small", file  /work/stupc/flatcc-master/src/runtime/json_printer.c, line 815
IOT/Abort trap (core dumped)

@mikkelfj
Copy link
Contributor

thanks

@mikkelfj
Copy link
Contributor

mikkelfj commented Oct 20, 2016

I pushed a fix to the struct issue. In general structs are supported and do pass tests without this fix, but the Vec3_create(arg list) call did a double endian conversion, which isn't effective.

In more detail the builder has a concept of struct_start, user fills in returned pointer, and calls struct_end. The end call can be _end, or _end_pe if the struct is already stored endian converted. This fix ensures the end_pe version is being used because the struct was already assigned using assign_to_pe in the internal buffer.

There are several other issues I will look into separately.

@mikkelfj
Copy link
Contributor

Moving discussion to #13 and closing this issue - even if reflection doesn't fully work on big endian, the critical bug that affects little endian platforms has been fixed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants