[AETHER-1516] Barefoot/bmv2 drivers are never loaded

This happens when missing drivers are detected due to wiring issues
during the loading of top level drivers (like stratum). This patch
fixes the bundle wiring issues by putting order in the loading of the
apps.

Short story: the loading of the apps is done in a greedy way in the
app store. This patch introduces a local map to track down the locally
started apps and to discard the activation coming from other instances if the
required apps are not loaded yet locally.

The bug is typically triggered becauses the instances start in random order,
app store can miss events as it does not start at the same time in all instances.
The bundle restart increases the chances to trigger this issue.

Additionally, this patch improves logging of the app subsystem.

Change-Id: I88eb58c5e1fb5b361fc32654310c58040e5789cd
diff --git a/core/net/src/main/java/org/onosproject/app/impl/ApplicationManager.java b/core/net/src/main/java/org/onosproject/app/impl/ApplicationManager.java
index c7e28bd..6b18a04 100644
--- a/core/net/src/main/java/org/onosproject/app/impl/ApplicationManager.java
+++ b/core/net/src/main/java/org/onosproject/app/impl/ApplicationManager.java
@@ -297,6 +297,8 @@
                 changed = true;
             } else if (feature == null) {
                 log.warn("Feature {} not found", name);
+            } else if (log.isDebugEnabled()) {
+                log.debug("Feature already installed for {}", app.id());
             }
         }
         return changed;
diff --git a/core/store/dist/src/main/java/org/onosproject/store/app/DistributedApplicationStore.java b/core/store/dist/src/main/java/org/onosproject/store/app/DistributedApplicationStore.java
index 2737b58..d71c1b0 100644
--- a/core/store/dist/src/main/java/org/onosproject/store/app/DistributedApplicationStore.java
+++ b/core/store/dist/src/main/java/org/onosproject/store/app/DistributedApplicationStore.java
@@ -153,6 +153,9 @@
 
     private ApplicationId coreAppId;
 
+    // Apps started in this node.
+    private final Set<String> localStartedApps = Sets.newConcurrentHashSet();
+
     @Activate
     public void activate() {
         messageHandlingExecutor = newSingleThreadExecutor(groupedThreads("onos/store/app",
@@ -453,6 +456,9 @@
     private void activate(ApplicationId appId, boolean updateTime) {
         Versioned<InternalApplicationHolder> vAppHolder = apps.get(appId);
         if (vAppHolder != null) {
+            if (log.isTraceEnabled()) {
+                log.trace("Activating {}", appId);
+            }
             if (updateTime) {
                 updateTime(appId.name());
             }
@@ -531,6 +537,9 @@
                     return new InternalApplicationHolder(v.app(), v.state(), ImmutableSet.copyOf(permissions));
                 });
         if (permissionsChanged.get()) {
+            if (log.isTraceEnabled()) {
+                log.trace("Permission changed for {}", appId);
+            }
             notifyDelegate(new ApplicationEvent(APP_PERMISSIONS_CHANGED, appHolder.value().app()));
         }
     }
@@ -544,10 +553,21 @@
         @Override
         public void accept(Application app) {
             if (app != null) { // FIXME: Once ONOS-6977 is fixed
+                if (log.isTraceEnabled()) {
+                    log.trace("Received an activation for {}", app.id());
+                }
                 String appName = app.id().name();
                 installAppIfNeeded(app);
                 setActive(appName);
-                notifyDelegate(new ApplicationEvent(APP_ACTIVATED, app));
+                boolean ready = localStartedApps.containsAll(app.requiredApps());
+                if (ready && delegate != null) {
+                    notifyDelegate(new ApplicationEvent(APP_ACTIVATED, app));
+                    localStartedApps.add(appName);
+                } else if (delegate == null) {
+                    log.warn("Postponing app activation {} due to the delegate being null", app.id());
+                } else {
+                    log.warn("Postponing app activation {} due to req apps being not ready", app.id());
+                }
             }
         }
     }
@@ -574,8 +594,12 @@
             if ((event.type() == MapEvent.Type.INSERT || event.type() == MapEvent.Type.UPDATE) && newApp != null) {
                 setupApplicationAndNotify(appId, newApp.app(), newApp.state());
             } else if (event.type() == MapEvent.Type.REMOVE && oldApp != null) {
+                if (log.isTraceEnabled()) {
+                    log.trace("{} has been uninstalled", appId);
+                }
                 notifyDelegate(new ApplicationEvent(APP_UNINSTALLED, oldApp.app()));
                 purgeApplication(appId.name());
+                localStartedApps.remove(appId.name());
             } else {
                 log.warn("Can't perform {} on application {}", event.type(), event.key());
             }
@@ -586,10 +610,17 @@
         // ACTIVATED state is handled separately in NextAppToActivateValueListener
         if (state == INSTALLED) {
             fetchBitsIfNeeded(app);
+            if (log.isTraceEnabled()) {
+                log.trace("{} has been installed", app.id());
+            }
             notifyDelegate(new ApplicationEvent(APP_INSTALLED, app));
         } else if (state == DEACTIVATED) {
+            if (log.isTraceEnabled()) {
+                log.trace("{} has been deactivated", app.id());
+            }
             clearActive(appId.name());
             notifyDelegate(new ApplicationEvent(APP_DEACTIVATED, app));
+            localStartedApps.remove(appId.name());
         }
     }
 
@@ -652,6 +683,9 @@
                                     app.id().name(), node.id());
                             latch.countDown();
                             if (delegateInstallation) {
+                                if (log.isTraceEnabled()) {
+                                    log.trace("Delegate installation for {}", app.id());
+                                }
                                 notifyDelegate(new ApplicationEvent(APP_INSTALLED, app));
                             }
                         } else if (error != null) {