Parallelizing logging, and automatic compaction (Was seg fault when creating a new level/snapshot)

[whatsthecraic]

Hi there,

I'm facing a SEGV on a machine, when using multiple threads, even though invocations to #batch_edge are in mutual exclusion, protected by a lock. See attached log. A repro for the current crash is a bit dauting to provide as it will require extracting quite a bit of code, but it seems to occur when the machine is overloaded with more logical threads active than the amount of physical threads.

Let me know if you need more info.

output.log

[pradeep-k]

Without the testcase, it would be hard to understand why the crash happened.
Does it only occur when the system is overloaded?
Does a single threaded batch_edge() work fine?

[whatsthecraic]

I think a simple repro would be just to invoke batch_edge concurrently from multiple threads. With 1 or 2 threads I haven't hit the crash. On my machine, a relatively old octacore FX-8350, it occurs always when perfoming the updates concurrently with 8 logical threads.

[pradeep-k]

Can you tell me the number of edges that are in your dataset? What is the size of property? 64bit or 32bit GraphOne?
What is the size of RAM in your machine?

[whatsthecraic]

64-bit, undirected graph, the weights are 64-bit doubles, 16384 vertices, 67092481 edges in total, the vertex array is initialised with 64M vertices. I think the machine is 32GB but I need to double check as it's a different one from what I'm using right now.

[pradeep-k]

Thanks for the update. If possible, can you provide a pseudo code, and the data file.

If the data is a single text file, it would be hard to achieve parallelism for insertion. Do you have data hosted in multiple files?

[whatsthecraic]

oky, I'll send you a repro later this evening.

[whatsthecraic]

Attached repro: https://gist.github.com/whatsthecraic/b09dd7d5948dc21cf559abbab1c5743f
Compile it with:

clang++ -std=c++17 repro.cpp -DOVER_COMMIT -DDEL -DTBB -DPLAIN_GRAPH -DB64 -I<PATH_GRAPHONE>/src -I/home/dean/workspace/graphone/gview -I<PATH_GRAPHONE>/include -I<PATH_GRAPHONE>/onedata -I<PATH_GRAPHONE>/analytics -O0 -g3 -fno-limit-debug-info -Wall  -fopenmp -pthread <PATH_GRAPHONE_BUILD>/src/libsrc64.a <PATH_GRAPHONE_BUILD>/onedata/libonedata64.a -ltbb -o repro.out

# lldb -- ./repro.out 
(lldb) target create "./repro.out"
Current executable set to './repro.out' (x86_64).
(lldb) r
Process 87329 launched: repro.out' (x86_64)
Generating the stream of edges ... 
Inserting 16384 vertices...
Inserting 67092481 edges with 12 threads ...
corrupted size vs. prev_size
Process 87329 stopped
* thread #24, name = 'repro.out', stop reason = signal SIGABRT
    frame #0: 0x00007ffff797ff25 libc.so.6`__GI_raise + 325
libc.so.6`__GI_raise:
->  0x7ffff797ff25 <+325>: movq   0x108(%rsp), %rax
    0x7ffff797ff2d <+333>: xorq   %fs:0x28, %rax
    0x7ffff797ff36 <+342>: jne    0x7ffff797ff5c            ; <+380>
    0x7ffff797ff38 <+344>: movl   %r8d, %eax
(lldb) bt
* thread #24, name = 'repro.out', stop reason = signal SIGABRT
  * frame #0: 0x00007ffff797ff25 libc.so.6`__GI_raise + 325
    frame #1: 0x00007ffff7969897 libc.so.6`__GI_abort + 299
    frame #2: 0x00007ffff79c3258 libc.so.6`__libc_message + 696
    frame #3: 0x00007ffff79ca77a libc.so.6`malloc_printerr + 26
    frame #4: 0x00007ffff79cb006 libc.so.6`unlink_chunk.isra.0 + 182
    frame #5: 0x00007ffff79cc4bb libc.so.6`_int_free + 1611
    frame #6: 0x0000555555562be5 repro.out`edge_shard_t<dst_weight_t<__univeral_type> >::cleanup(this=0x00005555555af560) at edge_sharding.h:146:13
    frame #7: 0x000055555556165e repro.out`edge_shard_t<dst_weight_t<__univeral_type> >::classify_u(this=0x00005555555af560, pgraph=0x00005555555af2c0) at edge_sharding.h:216:5
    frame #8: 0x000055555555c279 repro.out`::.omp_outlined._debug__(.global_tid.=0x00007ffe56ff9e20, .bound_tid.=0x00007ffe56ff9e18, this=0x00005555555af2c0) at sgraph2.h:59:41
    frame #9: 0x000055555555c2f5 repro.out`::.omp_outlined.(.global_tid.=0x00007ffe56ff9e20, .bound_tid.=0x00007ffe56ff9e18, this=0x00005555555af2c0) at sgraph2.h:57:5
    frame #10: 0x00007ffff7bed763 libomp.so`__kmp_invoke_microtask + 147
    frame #11: 0x00007ffff7b8c91d libomp.so`___lldb_unnamed_symbol279$$libomp.so + 301
    frame #12: 0x00007ffff7b8b92a libomp.so`___lldb_unnamed_symbol268$$libomp.so + 314
    frame #13: 0x00007ffff7bdd302 libomp.so`___lldb_unnamed_symbol869$$libomp.so + 354
    frame #14: 0x00007ffff7b164cf libpthread.so.0`start_thread + 223
    frame #15: 0x00007ffff7a432d3 libc.so.6`__GI___clone + 67

On my machine it crashes almost immediately.

[pradeep-k]

Test passed. Commit id is 54e8501

pkumar@mira:~/src/GraphOne/build$ ./graphone64
Generating the stream of edges ...
Inserting 16384 vertices...
Inserting 67092481 edges with 20 threads ...
Build ...
Done

This is a critical fix, and has not been thoroughly tested. If you see any thing being broken. Please post.

[whatsthecraic]

Hi @pradeep-k . Thanks for the quick fix! It improves, still I'm not able to validate the results. Attached a test case extracted from our suite.

See test: https://gist.github.com/whatsthecraic/5c5fc7c8dcc082a5cf1cd36a955046eb

log2.txt

[whatsthecraic]

This assertion is hit when running the test case for 10 seconds:

cpp_hello_graphone: /linux/workspace/graphone/onedata/mem_pool.h:147: status_t thd_mem_t<dst_weight_t<__univeral_type> >::delta_adjlist_bulk(index_t) [T = dst_weight_t<__univeral_type>]: Assertion `mem1->adjlog_beg' failed.

Thread 326 "cpp_hello_graph" received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffe3e2c3800 (LWP 23305)]
0x00007ffff796ef25 in raise () from /usr/lib/libc.so.6
(gdb) bt
#0  0x00007ffff796ef25 in raise () from /usr/lib/libc.so.6
#1  0x00007ffff7958897 in abort () from /usr/lib/libc.so.6
#2  0x00007ffff7958767 in __assert_fail_base.cold () from /usr/lib/libc.so.6
#3  0x00007ffff7967526 in __assert_fail () from /usr/lib/libc.so.6
#4  0x000055555557417b in thd_mem_t<dst_weight_t<__univeral_type> >::delta_adjlist_bulk (this=0x5555555eacc0, 
    size=18446744073708879872) at /linux/workspace/graphone/onedata/mem_pool.h:147
#5  0x0000555555573fd0 in thd_mem_t<dst_weight_t<__univeral_type> >::alloc_adjlist (this=0x5555555eacc0, 
    count=-42233, hub=true) at /linux/workspace/graphone/onedata/mem_pool.h:108
#6  0x0000555555573dee in onegraph_t<dst_weight_t<__univeral_type> >::new_delta_adjlist (this=0x5555555eabc0, 
    count=-42233, hub=true) at /linux/workspace/graphone/onedata/graph_base.h:143
#7  0x0000555555573802 in onegraph_t<dst_weight_t<__univeral_type> >::del_nebr_noatomic (this=0x5555555eabc0, vid=4, 
    sid=...) at /linux/workspace/graphone/onedata/onegraph.h:186
#8  0x0000555555573256 in onegraph_t<dst_weight_t<__univeral_type> >::archive (this=0x5555555eabc0, 
    edges=0x7ffe38050c30, count=24759, a_snapid=6) at /linux/workspace/graphone/onedata/onegraph.h:37
#9  0x0000555555576248 in edge_shard_t<dst_weight_t<__univeral_type> >::archive (this=0x5555555e8a50, 
    sgraph=0x5555555e8a30, global_range=0x5555555e8aa0, j_start=2, j_end=3, snap_id=5)
    at /linux/workspace/graphone/src/edge_sharding.h:799
#10 0x0000555555574d78 in edge_shard_t<dst_weight_t<__univeral_type> >::classify_u (this=0x5555555e8a50, 
    pgraph=0x5555555e7780) at /linux/workspace/graphone/src/edge_sharding.h:214
#11 0x000055555555efe9 in .omp_outlined._debug__(pgraph_t<dst_weight_t<__univeral_type> > *) const (
    .global_tid.=0x7ffe3e2c2be0, .bound_tid.=0x7ffe3e2c2bd8, this=0x5555555e7780)
    at /linux/workspace/graphone/src/sgraph2.h:59
#12 0x000055555555f065 in .omp_outlined.(void) const (.global_tid.=0x7ffe3e2c2be0, .bound_tid.=0x7ffe3e2c2bd8, 
    this=0x5555555e7780) at /linux/workspace/graphone/src/sgraph2.h:57
#13 0x00007ffff7bba763 in __kmp_invoke_microtask () from /usr/lib/libomp.so
#14 0x00007ffff7b5991d in ?? () from /usr/lib/libomp.so
#15 0x00007ffff7b5892a in ?? () from /usr/lib/libomp.so
#16 0x00007ffff7baa302 in ?? () from /usr/lib/libomp.so
#17 0x00007ffff7f744cf in start_thread () from /usr/lib/libpthread.so.0
#18 0x00007ffff7a322d3 in clone () from /usr/lib/libc.so.6

[whatsthecraic]

parallel variant: https://gist.github.com/whatsthecraic/3cfd93104fac87670fdefcc1e5bf046f

[pradeep-k]

Hi @pradeep-k . Thanks for the quick fix! It improves, still I'm not able to validate the results. Attached a test case extracted from our suite.

See test: https://gist.github.com/whatsthecraic/5c5fc7c8dcc082a5cf1cd36a955046eb

log2.txt

I forgot to mention you last time that the check for eOK after batch_edge() is invalid. You should check for eOK and eEndBatch both, or you can assume it will take care of everything. There is not error returned from this function.

This makes the testcase success.

[pradeep-k]

This assertion is hit when running the test case for 10 seconds:

cpp_hello_graphone: /linux/workspace/graphone/onedata/mem_pool.h:147: status_t thd_mem_t<dst_weight_t<__univeral_type> >::delta_adjlist_bulk(index_t) [T = dst_weight_t<__univeral_type>]: Assertion `mem1->adjlog_beg' failed.

Thread 326 "cpp_hello_graph" received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffe3e2c3800 (LWP 23305)]
0x00007ffff796ef25 in raise () from /usr/lib/libc.so.6
(gdb) bt
#0  0x00007ffff796ef25 in raise () from /usr/lib/libc.so.6
#1  0x00007ffff7958897 in abort () from /usr/lib/libc.so.6
#2  0x00007ffff7958767 in __assert_fail_base.cold () from /usr/lib/libc.so.6
#3  0x00007ffff7967526 in __assert_fail () from /usr/lib/libc.so.6
#4  0x000055555557417b in thd_mem_t<dst_weight_t<__univeral_type> >::delta_adjlist_bulk (this=0x5555555eacc0, 
    size=18446744073708879872) at /linux/workspace/graphone/onedata/mem_pool.h:147
#5  0x0000555555573fd0 in thd_mem_t<dst_weight_t<__univeral_type> >::alloc_adjlist (this=0x5555555eacc0, 
    count=-42233, hub=true) at /linux/workspace/graphone/onedata/mem_pool.h:108
#6  0x0000555555573dee in onegraph_t<dst_weight_t<__univeral_type> >::new_delta_adjlist (this=0x5555555eabc0, 
    count=-42233, hub=true) at /linux/workspace/graphone/onedata/graph_base.h:143
#7  0x0000555555573802 in onegraph_t<dst_weight_t<__univeral_type> >::del_nebr_noatomic (this=0x5555555eabc0, vid=4, 
    sid=...) at /linux/workspace/graphone/onedata/onegraph.h:186
#8  0x0000555555573256 in onegraph_t<dst_weight_t<__univeral_type> >::archive (this=0x5555555eabc0, 
    edges=0x7ffe38050c30, count=24759, a_snapid=6) at /linux/workspace/graphone/onedata/onegraph.h:37
#9  0x0000555555576248 in edge_shard_t<dst_weight_t<__univeral_type> >::archive (this=0x5555555e8a50, 
    sgraph=0x5555555e8a30, global_range=0x5555555e8aa0, j_start=2, j_end=3, snap_id=5)
    at /linux/workspace/graphone/src/edge_sharding.h:799
#10 0x0000555555574d78 in edge_shard_t<dst_weight_t<__univeral_type> >::classify_u (this=0x5555555e8a50, 
    pgraph=0x5555555e7780) at /linux/workspace/graphone/src/edge_sharding.h:214
#11 0x000055555555efe9 in .omp_outlined._debug__(pgraph_t<dst_weight_t<__univeral_type> > *) const (
    .global_tid.=0x7ffe3e2c2be0, .bound_tid.=0x7ffe3e2c2bd8, this=0x5555555e7780)
    at /linux/workspace/graphone/src/sgraph2.h:59
#12 0x000055555555f065 in .omp_outlined.(void) const (.global_tid.=0x7ffe3e2c2be0, .bound_tid.=0x7ffe3e2c2bd8, 
    this=0x5555555e7780) at /linux/workspace/graphone/src/sgraph2.h:57
#13 0x00007ffff7bba763 in __kmp_invoke_microtask () from /usr/lib/libomp.so
#14 0x00007ffff7b5991d in ?? () from /usr/lib/libomp.so
#15 0x00007ffff7b5892a in ?? () from /usr/lib/libomp.so
#16 0x00007ffff7baa302 in ?? () from /usr/lib/libomp.so
#17 0x00007ffff7f744cf in start_thread () from /usr/lib/libpthread.so.0
#18 0x00007ffff7a322d3 in clone () from /usr/lib/libc.so.6

This testcase is little confusing to me. I didn't understand the flow. How many total edges are finally there? How many of them are deleted edges per vertex? The typedef allocates only 16bits for deleted edge count per vertex?

While I work on it, can you modify and print some log for number of total edges, deleted edges on total, like you did in previous cases.

[whatsthecraic]

Hi @pradeep-k, what's the meaning of eEndBatch?

[whatsthecraic]

It expects 33 vertices and 90 edges. The thread simply keeps inserting and removing them.
The edges for vertex 1 should be : 2, 3, 4, 5, 6, 7, 8, 9, ... , 32, 33
vertex 2: 1, 4, 6, 8, 10, 12, 14 ..., 32
vertex 3: 1, 6, 9, 12, ... 30, 33
vertex 4: 1, 2, 8, 12, ...., 32
vertex 5: 1, 10... , 30
vertex 6: 1, 2, 3, 12, ..., 30
... so on ...