Fixed ProfileObserver.update race with multiple query threads

[simantics/platform.git] / bundles / org.simantics.scenegraph.profile / src / org / simantics / scenegraph / profile / common / ProfileObserver.java

diff --git a/bundles/org.simantics.scenegraph.profile/src/org/simantics/scenegraph/profile/common/ProfileObserver.java b/bundles/org.simantics.scenegraph.profile/src/org/simantics/scenegraph/profile/common/ProfileObserver.java
index efac19055944c8a2ab3bc713dd3100647755d9f8..440ee2714aada5e1effad128b3b4b03a6d10f98e 100644 (file)
--- a/bundles/org.simantics.scenegraph.profile/src/org/simantics/scenegraph/profile/common/ProfileObserver.java
+++ b/bundles/org.simantics.scenegraph.profile/src/org/simantics/scenegraph/profile/common/ProfileObserver.java
@@ -11,8 +11,10 @@
  *******************************************************************************/
 package org.simantics.scenegraph.profile.common;
 
+import java.util.ArrayList;
 import java.util.Collection;
 import java.util.HashMap;
+import java.util.List;
 import java.util.Map;
 import java.util.concurrent.TimeUnit;
 
@@ -21,22 +23,28 @@ import org.simantics.db.AsyncRequestProcessor;
 import org.simantics.db.Resource;
 import org.simantics.db.Session;
 import org.simantics.db.common.session.SessionEventListenerAdapter;
-import org.simantics.db.common.utils.Logger;
 import org.simantics.db.procedure.Procedure;
+import org.simantics.db.service.QueryControl;
 import org.simantics.db.service.SessionEventSupport;
 import org.simantics.scenegraph.INode;
 import org.simantics.scenegraph.g2d.G2DSceneGraph;
 import org.simantics.scenegraph.profile.EvaluationContext;
 import org.simantics.scenegraph.profile.ProfileEntry;
+import org.simantics.scenegraph.profile.Style;
 import org.simantics.scenegraph.profile.impl.DebugPolicy;
 import org.simantics.scenegraph.profile.impl.ProfileActivationListener;
 import org.simantics.scenegraph.profile.request.RuntimeProfileActiveEntries;
+import org.simantics.utils.datastructures.Pair;
 import org.simantics.utils.datastructures.disposable.IDisposable;
 import org.simantics.utils.threads.IThreadWorkQueue;
 import org.simantics.utils.threads.ThreadUtils;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 public class ProfileObserver implements EvaluationContext {
 
+    private static final Logger LOGGER = LoggerFactory.getLogger(ProfileObserver.class);
+
     private final Session                     session;
 
     /**
@@ -51,9 +59,13 @@ public class ProfileObserver implements EvaluationContext {
     private final Runnable                    notification;
     private final G2DSceneGraph               sceneGraph;
 
-    private boolean                           dirty               = true;
-    private boolean                           disposed            = false;
+    private volatile boolean                  dirty               = true;
+    private volatile boolean                  disposed            = false;
 
+    private boolean                           needSynchronizedUpdates = false;
+    private List<Pair<Style, Object>>         updates             = new ArrayList<>();
+    private boolean                           updateAll;
+    
     private ProfileActivationListener         activationListener;
 
     private Map<String, Object>               constants           = new HashMap<String, Object>();
@@ -88,6 +100,7 @@ public class ProfileObserver implements EvaluationContext {
         this.sceneGraph = sceneGraph;
         this.constants.putAll(constants);
         this.notification = notification;
+        this.needSynchronizedUpdates = session.getService(QueryControl.class).getAmountOfQueryThreads() > 1;
 
         attachSessionListener();
 
@@ -129,12 +142,26 @@ public class ProfileObserver implements EvaluationContext {
     }
 
     @Override
-    public void update() {
+    public void update(Style style, Object item) {
         if (DebugPolicy.DEBUG_PROFILE_OBSERVER_UPDATE)
             System.out.println("Profile observer marked dirty.");
+
+        if (needSynchronizedUpdates) {
+            synchronized (updates) {
+                updates.add(Pair.make(style, item));
+            }
+        } else {
+            updates.add(Pair.make(style, item));
+        }
+        //updateAll = true;
         dirty = true;
     }
 
+    public void update() {
+        updateAll = true;
+        dirty = true;
+    }
+    
     private void perform() {
         dirty = false;
         if (DebugPolicy.DEBUG_PROFILE_OBSERVER_UPDATE)
@@ -148,39 +175,54 @@ public class ProfileObserver implements EvaluationContext {
                     return;
 
                 ThreadUtils.asyncExec(thread, new Runnable() {
-                    
-//                    private void init(INode node) {
-//                        //ProfileVariables.init(node, ProfileObserver.this);
-////                        NodeUtil.forChildren(node, new NodeProcedure<Object>() {
-////                            @Override
-////                            public Object execute(INode node, String id) {
-////                                init(node);
-////                                return null;
-////                            }
-////                        }, null);
-//                    }
-
                     @Override
                     public void run() {
-
                         if (isDisposed())
                             return;
 
                         temporaryProperties.clear();
 
-//                        init(sceneGraph);
-
-//                        for(IElement e : diagram.getElements()) {
-//                            Node node = NodeUtils.
-//                            Variables.init(e, ProfileObserver.this);
-//                        }
-
-                        for(ProfileEntry e : entries) {
-                            if (DebugPolicy.DEBUG_PROFILE_OBSERVER_PERFORM)
-                                System.out.println("Apply profile entry: " + e);
-                            e.apply(ProfileObserver.this);
+                        long t0 = DebugPolicy.DEBUG_PROFILE_OBSERVER_PERFORM ? System.nanoTime() : 0L;
+                        
+                        if (updateAll) {
+                            for(ProfileEntry e : entries) {
+                                if (DebugPolicy.DEBUG_PROFILE_OBSERVER_PERFORM)
+                                    System.out.println("Apply profile entry: " + e);
+                                e.apply(ProfileObserver.this);
+                            }
+                            updateAll = false;
+                            if (needSynchronizedUpdates) {
+                                synchronized (updates) {
+                                    updates.clear();
+                                }
+                            } else {
+                                updates.clear();
+                            }
+                        } else {
+                            List<Pair<Style, Object>> updatesCopy;
+                            if (needSynchronizedUpdates) {
+                                synchronized (updates) {
+                                    updatesCopy = new ArrayList<>(updates);
+                                    updates.clear();
+                                }
+                            } else {
+                                updatesCopy = new ArrayList<>(updates);
+                                updates.clear();
+                            }
+
+                            for (Pair<Style, Object> update : updatesCopy) {
+                                Style style = update.first;
+                                Object item = update.second;
+                                
+                                style.apply2(item, ProfileObserver.this);
+                            }
                         }
 
+                        if (DebugPolicy.DEBUG_PROFILE_OBSERVER_PERFORM) {
+                            long t1 = System.nanoTime();
+                            System.out.println((t1-t0) / 1e6);
+                        }
+                        
                         if(dirty) {
                                sceneGraph.setPending(ProfileObserver.this);
 //                             System.err.println("setPending, dirty=true");
@@ -194,28 +236,19 @@ public class ProfileObserver implements EvaluationContext {
 //                        canvas.getContentContext().setDirty();
                         
                         // Something is underway, schedule update
-                        if(dirty) {
-                               Simantics.async(new Runnable() {
-
-                                                               @Override
-                                                               public void run() {
-
-                                                           if (isDisposed()) return;
-                                                           
-                                                                       if(dirty) perform();
-                                                                       
-                                                               }
-                                       
-                               }, 100, TimeUnit.MILLISECONDS);
+                        if (dirty) {
+                            Simantics.async(() -> {
+                                if (isDisposed()) return;
+                                if (dirty) perform();
+                            }, 100, TimeUnit.MILLISECONDS);
                         }
-
                     }
                 });
             }
 
             @Override
             public void exception(Throwable t) {
-                Logger.defaultLogError(t);
+                LOGGER.error("RuntimeProfileActiveEntries request failed", t);
             }
         });
     }
@@ -227,7 +260,7 @@ public class ProfileObserver implements EvaluationContext {
 
     @Override
     public void exception(Throwable throwable) {
-        Logger.defaultLogError(throwable);
+        LOGGER.error("Exception occurred during diagram profile observation", throwable);
     }
 
     @SuppressWarnings("unchecked")