Exchange one-to-one Communication time more than Total Time

[seydang]

The "taking X seconds" values in the Communication details do not appear to be reflecting elapsed wall-clock time. For example, with N=32 and MASCOT protocol, for a simple normalization operation (script attached below), party 0 reports:

Exchanging one-to-one 46143.9 MB in 2850 rounds, taking 570.35 seconds

But the total time for the entire execution is only 268.7 seconds:

Time = 268.6922 seconds (from: Spent 2.3542 seconds (10.0918 MB, 18249 rounds) on the online phase and 266.338 seconds (50649.2 MB, 12295 rounds) on the preprocessing/offline phase.

Summing all "taking" values exceeds the total time even further.

Is this the intended behavior? If so, is there a way to obtain per-party wall-clock communication time (i.e., time blocked waiting on the network) from MP-SPDZ's instrumentation?

To reproduce

normalize_32.mpc:

sfix.set_precision(53, 64);   
n = 32
q_r = Array(n, sfix)

@for_range(n)
def _(i):
    q_r[i] = sfix.get_input_from(i)

sum_qr = sum(q_r)

ratios = Array(n, sfix)
@for_range(n)
def _(i):
    ratios[i] = q_r[i] / sum_qr

./compile.py --budget 100000 normalize_32
for pid in $(seq 0 31); do
  "mascot-party.x" $pid normalize_32 -N 32 -pn 18000 -v 2>party$pid_full.log &
done

Outputs
Using prime modulus 170141183460469231731687303715885907969
Setup took 0.719955 seconds.
Compiler: ./compile.py --budget 100000 normalize_32
Tinier open counter: 0
4 triples of SPDZ gfp left
616 bits of SPDZ gfp left
Detailed costs:
1 integer inputs
9936 integer multiplications
94096 integer openings
Spent 2.3542 seconds (10.0918 MB, 18249 rounds) on the online phase and 266.338 seconds (50649.2 MB, 12295 rounds) on the preprocessing/offline phase.
Communication details:
Broadcasting 0.039688 MB in 1029 rounds, taking 4.80966 seconds
Exchanging one-to-one 46143.9 MB in 2850 rounds, taking 570.35 seconds
Receiving directly 57.1873 MB in 10509 rounds, taking 2.1569 seconds
Receiving one-to-one 4456.09 MB in 2896 rounds, taking 0.414526 seconds
Sending directly 58.6894 MB in 10332 rounds, taking 0.233092 seconds
Sending one-to-one 4456.09 MB in 2896 rounds, taking 0.0588089 seconds
Sending to all 3.2e-05 MB in 16 rounds, taking 0.00097238 seconds
Sending/receiving 0.00384 MB in 16 rounds, taking 0.0182936 seconds
CPU time = 516.572
Actual preprocessing cost of program:
Type int
9936 Triples
36384 Bits
16 Input tuples (1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1)
Coordination took 0.299593 seconds
Command line: /mascot-party.x 0 normalize_32 -N 32 -pn 13000 -v

MP-SPDZ version
v0.4.2

Additional context
I am benchmarking MPC protocols across party counts (N=2 to 32) and would like to report a compute vs. communication breakdown per party. Any guidance on the correct way to extract this from MP-SPDZ would be appreciated.

[mkskeller]

This is because one-to-one communication is run a thread per party and thus counted multiple times. Dividing the amount by N-1 should give an idea of the wall clock time.

[seydang]

Thank you!