Hi all,
we monitored one of our programs and observed a strange behaviour: the
compiler-annotation @Uncounted seems to slow down program execution. I
constructed a sample program (attached) to simulate the behaviour
(please ignore any kind of synchronization problem, I tried to keep the
test as simple as possible).
I compiled the attached program with the current git-version of X10. The
tests were conducted with the default (sockets) and mpi (OpenMPI
1.7.1ULFM) RT implementations. Envirnoment variables were set to
X10_NPLACES=2 and X10_NTHREADS=1. The program output is in the
corresponding attachments.
Bottom line: with the socket implementation, at (...) @Uncounted async {
... } seems to be slower than or equally fast as a "normal" at (...)
async { ... }. With the MPI implementation, execution times are as
expected (@Uncounted is faster than its counterpart). I was able to
observe this behaviour on two different machines (both linux, one Ubuntu
16.04.1 LTS, the other a CentOS Linux release 7.2.1511). Is there
something wrong within the sockets implementation or is this behaviour
expected? If this is expected behaviour, could someone tell me why, with
sockets RT, an at @Uncounted async is slower?
Thanks and cheers,
Marco
import x10.compiler.Uncounted;
public class Test
{
public static val target:Place = Place(1);
public static val counter:Cell[Int] = new Cell[Int](0n);
public static def main(val args:Rail[String]) : void
{
val EXECUTIONS:Long = Long.parseLong(args(0));
val RUNS:Long = Long.parseLong(args(1));
val SLEEP:Long = Long.parseLong(args(2));
val COOLDOWN:Long = Long.parseLong(args(3));
Console.OUT.println("[MASTER " + here + "]: starting test...");
for (var execution:Long = 0; execution < EXECUTIONS; ++execution)
{
Console.OUT.println("--------------------------------------------------------------------------------");
Console.OUT.println("[MASTER " + here + "]: starting execution " +
execution);
var timeForAtAsync:Long = 0;
Console.OUT.print("[MASTER " + here + "]: starting asyncAt test...");
for (var run:Long = 0; run < RUNS; ++run)
{
at (target) async
{
sleep(SLEEP);
}
timeForAtAsync += asyncAt();
}
val seondsForAtAsync:Double = timeForAtAsync / 1000000000.0;
val meansForAtAsync:Double = timeForAtAsync / RUNS;
Console.OUT.println(" done!");
Console.OUT.println( "[MASTER " + here + "]: sleeping " + COOLDOWN
+ " ms to let all "
+ "open activities finish.");
System.sleep(COOLDOWN);
var timeForAtUncountedAsync:Long = 0;
Console.OUT.print("[MASTER " + here + "]: starting asyncUncountedAt
test...");
for (var run:Long = 0; run < RUNS; ++run)
{
at (target) async
{
sleep(SLEEP);
}
timeForAtUncountedAsync += asyncAt();
}
val seondsForAtUncountedAsync:Double = timeForAtUncountedAsync /
1000000000.0;
val meansForAtUncountedAsync:Double = timeForAtUncountedAsync / RUNS;
Console.OUT.println(" done!");
Console.OUT.println( "[MASTER " + here + "]: sleeping " + COOLDOWN
+ " ms to let all "
+ "open activities finish.");
System.sleep(COOLDOWN);
Console.OUT.println("[MASTER " + here + "]: test statistics: ");
Console.OUT.println( "[MASTER " + here + "]: asyncAt: " + RUNS + "
runs in "
+ seondsForAtAsync + " seconds -> " +
meansForAtAsync + " ns per "
+ "run.");
Console.OUT.println( "[MASTER " + here + "]: asyncUncountedAt: " +
RUNS + " runs in "
+ seondsForAtUncountedAsync + " seconds -> "
+ meansForAtUncountedAsync + " ns per run.");
Console.OUT.println("[MASTER " + here + "]: execution " + execution
+ " done.");
}
}
public static def asyncAt() : Long
{
val start:Long = System.nanoTime();
at (target) async
{
++counter.value;
}
return (System.nanoTime() - start);
}
public static def asyncUncountedAt() : Long
{
val start:Long = System.nanoTime();
at (target) @Uncounted async
{
++counter.value;
}
return (System.nanoTime() - start);
}
public static def sleep(val millis:Long) : void
{
System.sleep(millis);
}
}$> export X10_NPLACES=2 X10_NTHREADS=1
$> x10c++ ../src/Test.x10 -O -NO_CHECKS -x10rt mpi -o TestMPI
$> mpirun -n 2 ./TestMPI 5 500 1000 2000
[MASTER Place(0)]: starting test...
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 0
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.005306491 seconds -> 10612.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.004990042 seconds -> 9980.0
ns per run.
[MASTER Place(0)]: execution 0 done.
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 1
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.003757229 seconds -> 7514.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.002313914 seconds -> 4627.0
ns per run.
[MASTER Place(0)]: execution 1 done.
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 2
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.002557401 seconds -> 5114.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.002331356 seconds -> 4662.0
ns per run.
[MASTER Place(0)]: execution 2 done.
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 3
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.005474053 seconds -> 10948.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.001140575 seconds -> 2281.0
ns per run.
[MASTER Place(0)]: execution 3 done.
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 4
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.003045775 seconds -> 6091.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.001411739 seconds -> 2823.0
ns per run.
[MASTER Place(0)]: execution 4 done.
$> export X10_NPLACES=2 X10_NTHREADS=1
$> x10c++ ../src/Test.x10 -O -NO_CHECKS -o Test
$> ./Test 5 500 1000 2000
[MASTER Place(0)]: starting test...
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 0
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.004497004 seconds -> 8994.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.015261572 seconds -> 30523.0
ns per run.
[MASTER Place(0)]: execution 0 done.
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 1
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.014243676 seconds -> 28487.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.015791758 seconds -> 31583.0
ns per run.
[MASTER Place(0)]: execution 1 done.
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 2
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.014250774 seconds -> 28501.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.013985158 seconds -> 27970.0
ns per run.
[MASTER Place(0)]: execution 2 done.
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 3
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.012388193 seconds -> 24776.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.01247958 seconds -> 24959.0
ns per run.
[MASTER Place(0)]: execution 3 done.
--------------------------------------------------------------------------------
[MASTER Place(0)]: starting execution 4
[MASTER Place(0)]: starting asyncAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: starting asyncUncountedAt test... done!
[MASTER Place(0)]: sleeping 2000 ms to let all open activities finish.
[MASTER Place(0)]: test statistics:
[MASTER Place(0)]: asyncAt: 500 runs in 0.009514611 seconds -> 19029.0 ns per
run.
[MASTER Place(0)]: asyncUncountedAt: 500 runs in 0.008901585 seconds -> 17803.0
ns per run.
[MASTER Place(0)]: execution 4 done.
------------------------------------------------------------------------------
What NetFlow Analyzer can do for you? Monitors network bandwidth and traffic
patterns at an interface-level. Reveals which users, apps, and protocols are
consuming the most bandwidth. Provides multi-vendor support for NetFlow,
J-Flow, sFlow and other flows. Make informed decisions using capacity planning
reports.http://sdm.link/zohodev2dev
_______________________________________________
X10-users mailing list
X10-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/x10-users
