Add more extensive tracing for actor constructs #55

daumayr · 2016-11-16T10:00:32Z

Trace actor creation, messages, promises
send trace to debuger
write trace to file
print report about number of actors, messages and promises

smarr

A bunch of cleanups

smarr · 2016-11-16T14:37:22Z

src/tools/actors/ActorExecutionTrace.java

+            .out.println(info.getGcAction() + ": - " + info.getGcInfo().getId() + " " + info.getGcName() + " (from " + info.getGcCause() + ") " + info.getGcInfo().getDuration() + " ms;");
+            .out.println("GcInfo MemoryUsageBeforeGc: " + info.getGcInfo().getMemoryUsageBeforeGc().entrySet().stream().filter(ent -> !ent.getKey().equals("Compressed Class Space") && !ent.getKey().equals("Code Cache")).mapToLong(usage -> usage.getValue().getUsed()).sum() / 1024 + " kB");
+            .out.println("GcInfo MemoryUsageAfterGc: " + info.getGcInfo().getMemoryUsageAfterGc().entrySet().stream().filter(ent -> !ent.getKey().equals("Compressed Class Space") && !ent.getKey().equals("Code Cache")).mapToLong(usage -> usage.getValue().getUsed()).sum() / 1024 + " kB");
+            */


I would prefer to either have this done completely, i.e., with the output in here. Or removed. Ideally we don't check in 'dead code'.

smarr · 2016-11-16T14:38:31Z

som

@@ -67,6 +67,8 @@ tools.add_argument('-dm', '--dynamic-metrics', help='Capture Dynamic Metrics',
                    dest='dynamic_metrics', action='store_true', default=False)
 tools.add_argument('-at', '--actor-tracing', help='enable tracing of actor operations',
                    dest='actor_tracing', action='store_true', default=False)
+tools.add_argument('-mt', '--memory-tracing', help='enable tracing of memory usage and GC',
+                    dest='memory_tracing', action='store_true', default=False)


Ah, useful. Nice. Thanks :)

For the future, if you have those things that are useful separately, would be great if they could be in a separate pull request. But, it's ok to leave it in here.

smarr · 2016-11-16T14:40:11Z

src/som/VM.java

@@ -239,6 +240,13 @@ public static void println(final String msg) {
    // Checkstyle: resume
  }

+  @TruffleBoundary
+  public static void printReport(final String msg) {


Hm, this could use JavaDoc or a more explicit name. I think you use that for reporting specific things. Would be good to say what type of things these are (abstractly, not necessarily the concrete use case you have).

smarr · 2016-11-16T14:42:56Z

src/som/interpreter/actors/Actor.java


  /** Flag to indicate whether there is currently a F/J task executing. */
  private boolean isExecuting;

  /** Is scheduled on the pool, and executes messages to this actor. */
  private final ExecAllMessages executor;

+  //id totals
+  private static long mtotal = 0;


please use more than one letter to distinguish those. I assume messagesTotal or actorsTotal for instance?
Also the comment id totals reads strange. Those are counts (ok, derived from the id counters, but that doesn't really matter, right?), and as counts perhaps 'total' isn't the ideal term?

smarr · 2016-11-16T14:45:37Z

src/som/interpreter/actors/Actor.java

-    protected final ObjectBuffer<SFarReference> createdActors;
-    protected final ObjectBuffer<ObjectBuffer<EventualMessage>> processedMessages;
+    protected final long threadId;
+    protected long actorIdCounter = 1;


I would prefer to know from the variable name whether this is the last or the next id for an actor. Same for the other ids.
So, perhaps nextActorId?

smarr · 2016-11-16T15:49:09Z

src/tools/actors/ActorExecutionTrace.java

+  }
+
+
+  //Events


superflous comment

smarr · 2016-11-16T15:51:55Z

src/tools/actors/ActorExecutionTrace.java


-    if (VmSettings.ACTOR_TRACING) {
-      processedMessages = new ObjectBuffer<>(MSG_BUFFER_SIZE);
+    if (current instanceof ActorProcessingThread) {


this isn't depending on VmSettings.ACTOR_TRACING anymore?

smarr · 2016-11-16T15:53:06Z

tools/kompos/npm-debug.log

@@ -0,0 +1,289 @@
+0 info it worked if it ends with ok


please don't add such log files

smarr · 2016-11-16T15:53:36Z

tools/kompos/src/controller.ts

@@ -90,7 +90,16 @@ export class Controller {
  }

  onMessageHistory(msg: MessageHistoryMessage) {
-    displayMessageHistory(msg);


should the whole operation be removed?

smarr · 2016-11-16T15:54:15Z

tools/kompos/src/history-data.ts

+          i += 18;
+          break;
+        case 2:
+          //var pid = new Long(data.getInt32(i+4), data.getInt32(i)); //promise id


a lot of dead or unfinished code here?

smarr · 2016-11-29T08:57:55Z

src/som/VM.java

+   * This method is used to print reports about the number of created artifacts.
+   * For example actors, messages and promises.
+   */
+  public static void printArtifactsReport(final String msg) {


hm, is artifacts a good name here? how about ConcurrencyEntities instead?

smarr

Looks very good overall.
Just some minor things as usual.

Would try to run the benchmarks on this later today.

smarr · 2016-11-29T08:59:45Z

src/som/interpreter/actors/Actor.java

+    }
+
+    protected long generateActorId() {
+      long result = (threadId << 56) | nextActorId;


could you put the magic 56 into a private static final field so that it has a explanatory name?

smarr · 2016-11-29T09:01:03Z

src/som/interpreter/actors/EventualMessage.java

@@ -143,10 +151,10 @@ protected static Actor determineTargetAndWrapArguments(final Object[] arguments,

    protected final Actor originalSender; // initial owner of the arguments

-    public PromiseMessage(final EventualMessage causalMessage, final Object[] arguments, final Actor originalSender,
+    public PromiseMessage(final long causalMessageId, final Object[] arguments, final Actor originalSender,


let's ignore those for the moment

smarr · 2016-11-29T09:05:41Z

src/tools/actors/ActorExecutionTrace.java

+
+  private static void writeParameter(final Object param, final ByteBuffer b) {
+    if (param instanceof SPromise) {
+      b.put((byte) 0x04);


might be better to use the enum.id() (which you might want to add as getter) here.
Also, the age old question in software maintainability: should each if better be a polymorphic method on the class itself that takes the byte buffer? Not sure, but I I would prefer using the enum id as first step, to avoid trivial bugs.

smarr · 2016-11-29T09:07:54Z

src/tools/actors/ActorExecutionTrace.java

+      File folder = new File(System.getProperty("user.dir") + "/traces");
+      folder.mkdir();
+
+      File f = new File(folder.getAbsolutePath() + "/" + new Date().toString() + ".trace");


would be good if the trace file names could be configured as a option via the ./som launcher, possibly passed in via some -Dsom.trace$$ java property.
Then the trace file has a deterministic name and can be handled easier from scripts, which will be important for experiments.

smarr · 2016-11-29T09:09:58Z

src/tools/debugger/BinaryWebSocketHandler.java

+
+  @Override
+  public void onClose(final WebSocket conn, final int arg1, final String arg2, final boolean arg3) {
+    // TODO Auto-generated method stub


instead of the auto generated comment, for empty operations, I would prefer if you either leave the body blank, or have something like // no-op, or better, just remove the method if it wasn't abstract.

smarr · 2016-11-29T09:10:08Z

src/tools/debugger/BinaryWebSocketHandler.java

+
+  @Override
+  public void onMessage(final WebSocket conn, final String msg) {
+    // TODO Auto-generated method stub


same as above

- a useful actor id is only obtainable when actor tracing is enabled - changed actor and message ids in messagehistory from string to long - no longer keeps references to actors whose informations have been sent to debugger - print memory usage and GC information to console

- Tracing actor now has a field for the message that caused it's creation - hide memory tracing behind a VM setting ("-mt") - fix message ids

- new Mailbox type (extends ObjectBuffer) - has a tracing variant (similar to Actor/TracingActor) - timestamps - thread that executed it - actor that owned it (receiver of the messages) - id of the first message (id of messages can be calculated)

- timestamps for message sends and execution start are stored in the mailbox, because the type hierachy of messages is not suited for the approach used with tracing actors

- trace promise resolution - resolving message - causal message - chained/normal - actor id no longer lazy

- added threadlocal buffers - added worker thread for sending messages/writing to disk - write some data to the buffers (mainly ids)

- now dumps traced data into a file - Symbols now have an Id - fixed exiting when result is a promise - log more data

- now sends binary trace data to debugger - debugger uses binary data for actor graph - at the end of execution a report about the number of actors/messages/promises is printed (when tracing is active) - removed old tracing - rename method printArtifactsReport - no need to wait for binary socket when it is unused - force buffer swap

- PromiseMessages: now recorded individually - Changed mailbox/message part of trace format

- added parameter for trace file destination

smarr added the enhancement Improves the implementation with something noteworthy label Nov 16, 2016

smarr assigned smarr and daumayr Nov 16, 2016

smarr changed the title ~~Tracing~~ Add more extensive tracing for actor constructs Nov 16, 2016

smarr requested changes Nov 16, 2016

View reviewed changes

smarr reviewed Nov 29, 2016

View reviewed changes

smarr requested changes Nov 29, 2016

View reviewed changes

daumayr added 11 commits November 29, 2016 17:13

Causal message for Actor creation

054e264

- Tracing actor now has a field for the message that caused it's creation - hide memory tracing behind a VM setting ("-mt") - fix message ids

Implemented mailbox tracing

ed810df

- new Mailbox type (extends ObjectBuffer) - has a tracing variant (similar to Actor/TracingActor) - timestamps - thread that executed it - actor that owned it (receiver of the messages) - id of the first message (id of messages can be calculated)

Implemented message timestamps

9e6e256

- timestamps for message sends and execution start are stored in the mailbox, because the type hierachy of messages is not suited for the approach used with tracing actors

Implemented Promise Tracing

86f9425

- trace promise resolution - resolving message - causal message - chained/normal - actor id no longer lazy

DataFormat WIP

d9d379c

- added threadlocal buffers - added worker thread for sending messages/writing to disk - write some data to the buffers (mainly ids)

Tracing WIP

7f0e6c7

- now dumps traced data into a file - Symbols now have an Id - fixed exiting when result is a promise - log more data

Added trace folder to git ignore

87a1471

Improvements

f44c97e

- PromiseMessages: now recorded individually - Changed mailbox/message part of trace format

Implemented Feedback

392a021

- added parameter for trace file destination

smarr force-pushed the actor-graph-stepping branch from 479a687 to 392a021 Compare November 30, 2016 09:44

smarr approved these changes Nov 30, 2016

View reviewed changes

smarr merged commit c342b48 into smarr:master Nov 30, 2016

smarr deleted the actor-graph-stepping branch November 30, 2016 09:46

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add more extensive tracing for actor constructs #55

Add more extensive tracing for actor constructs #55

daumayr commented Nov 16, 2016

smarr left a comment

smarr Nov 16, 2016

smarr Nov 16, 2016

smarr Nov 16, 2016

smarr Nov 16, 2016

smarr Nov 16, 2016

smarr Nov 16, 2016

smarr Nov 16, 2016

smarr Nov 16, 2016

smarr Nov 16, 2016

smarr Nov 16, 2016

smarr Nov 29, 2016

smarr left a comment

smarr Nov 29, 2016

smarr Nov 29, 2016

smarr Nov 29, 2016

smarr Nov 29, 2016

smarr Nov 29, 2016

smarr Nov 29, 2016

Add more extensive tracing for actor constructs #55

Add more extensive tracing for actor constructs #55

Conversation

daumayr commented Nov 16, 2016

smarr left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

smarr left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment