View Javadoc

1   package com.atlassian.plugin.manager;
2   
3   import com.atlassian.plugin.Plugin;
4   import com.atlassian.plugin.PluginAccessor;
5   import com.atlassian.plugin.PluginController;
6   import com.atlassian.plugin.PluginState;
7   import com.atlassian.plugin.exception.PluginExceptionInterception;
8   import com.atlassian.plugin.util.PluginUtils;
9   import com.atlassian.plugin.util.WaitUntil;
10  import com.google.common.collect.ImmutableList;
11  import org.slf4j.Logger;
12  import org.slf4j.LoggerFactory;
13  
14  import java.util.ArrayList;
15  import java.util.Collection;
16  import java.util.HashSet;
17  import java.util.Iterator;
18  import java.util.Set;
19  import java.util.concurrent.CopyOnWriteArraySet;
20  import java.util.concurrent.TimeUnit;
21  
22  /**
23   * Helper class that handles the problem of enabling a set of plugins at once.  This functionality is used for both the
24   * initial plugin loading and manual plugin enabling.  The system waits 60 seconds for all dependencies to be resolved,
25   * then resets the timer to 5 seconds if only one remains.
26   *
27   * @since 2.2.0
28   */
29  class PluginEnabler
30  {
31      private static final Logger log = LoggerFactory.getLogger(PluginEnabler.class);
32      private static final long LAST_PLUGIN_TIMEOUT = 30 * 1000;
33      private static final long LAST_PLUGIN_WARN_TIMEOUT = 5 * 1000;
34  
35      private final PluginAccessor pluginAccessor;
36      private final PluginController pluginController;
37      private final PluginExceptionInterception pluginExceptionInterception;
38      private final Set<Plugin> pluginsBeingEnabled = new CopyOnWriteArraySet<Plugin>();
39  
40      public PluginEnabler(PluginAccessor pluginAccessor, PluginController pluginController, final PluginExceptionInterception pluginExceptionInterception)
41      {
42          this.pluginAccessor = pluginAccessor;
43          this.pluginController = pluginController;
44          this.pluginExceptionInterception = pluginExceptionInterception;
45      }
46  
47      /**
48       * Determines, recursively, which disabled plugins this plugin depends upon, and enables all of them at once.
49       * Returns the plugins that were successfully enabled, including dependencies that weren't explicitly specified.
50       *
51       * @param plugins The set of plugins to enable
52       * @return a collection of plugins that were actually enabled
53       */
54      Collection<Plugin> enableAllRecursively(Collection<Plugin> plugins)
55      {
56          Collection<Plugin> pluginsToEnable = new ArrayList<Plugin>();
57          Set<String> dependentKeys = new HashSet<String>();
58  
59          for (Plugin plugin : plugins)
60          {
61              scanDependencies(plugin, dependentKeys);
62          }
63  
64          for (String key : dependentKeys)
65          {
66              pluginsToEnable.add(pluginAccessor.getPlugin(key));
67          }
68          enable(pluginsToEnable);
69  
70          ImmutableList.Builder<Plugin> enabledPlugins = new ImmutableList.Builder<Plugin>();
71          for (Plugin plugin : pluginsToEnable)
72          {
73              if (plugin.getPluginState().equals(PluginState.ENABLED))
74              {
75                  enabledPlugins.add(plugin);
76              }
77          }
78          return enabledPlugins.build();
79      }
80  
81      /**
82       * @param plugin The plugin to test
83       * @return If the plugin is currently part of a set that is being enabled
84       */
85      boolean isPluginBeingEnabled(Plugin plugin)
86      {
87          return pluginsBeingEnabled.contains(plugin);
88      }
89  
90      /**
91       * Enables a collection of plugins at once, waiting for 60 seconds.  If any plugins are still in the enabling state,
92       * the plugins are explicitly disabled.
93       *
94       * @param plugins The plugins to enable
95       */
96      void enable(Collection<Plugin> plugins)
97      {
98          pluginsBeingEnabled.addAll(plugins);
99          try
100         {
101             actualEnable(plugins);
102         }
103         finally
104         {
105             pluginsBeingEnabled.removeAll(plugins);
106         }
107     }
108 
109     private void actualEnable(Collection<Plugin> plugins)
110     {
111         final Set<Plugin> pluginsInEnablingState = new HashSet<Plugin>();
112         for (final Plugin plugin : plugins)
113         {
114             try
115             {
116                 plugin.enable();
117                 if (plugin.getPluginState() == PluginState.ENABLING)
118                 {
119                     pluginsInEnablingState.add(plugin);
120                 }
121             }
122             catch (final RuntimeException ex)
123             {
124                 boolean logMsg = pluginExceptionInterception.onEnableException(plugin, ex);
125                 if (logMsg)
126                 {
127                     log.error("Unable to enable plugin " + plugin.getKey(), ex);
128                 }
129             }
130         }
131 
132         if (!pluginsInEnablingState.isEmpty())
133         {
134             // Now try to enable plugins that weren't enabled before, probably due to dependency ordering issues
135             WaitUntil.invoke(new WaitUntil.WaitCondition()
136             {
137                 private long singlePluginTimeout;
138                 private long singlePluginWarn;
139 
140                 public boolean isFinished()
141                 {
142                     if (singlePluginTimeout > 0 && singlePluginTimeout < System.currentTimeMillis())
143                     {
144                         return true;
145                     }
146                     for (final Iterator<Plugin> i = pluginsInEnablingState.iterator(); i.hasNext();)
147                     {
148                         final Plugin plugin = i.next();
149                         if (plugin.getPluginState() != PluginState.ENABLING)
150                         {
151                             i.remove();
152                         }
153                     }
154                     if (isAtlassianDevMode() && pluginsInEnablingState.size() == 1)
155                     {
156                         final long currentTime = System.currentTimeMillis();
157                         if (singlePluginTimeout == 0)
158                         {
159                             log.info("Only one plugin left not enabled. Resetting the timeout to " + (LAST_PLUGIN_TIMEOUT / 1000) + " seconds.");
160 
161                             singlePluginWarn = currentTime + LAST_PLUGIN_WARN_TIMEOUT;
162                             singlePluginTimeout = currentTime + LAST_PLUGIN_TIMEOUT;
163                         }
164                         else if (singlePluginWarn <= currentTime)
165                         {
166                             //PLUG-617: Warn people when it takes a long time to enable a plugin when in dev mode. We bumped
167                             //this timeout from 5 to 30 seconds because the gadget publisher in JIRA can take this long to
168                             //load when running java in DEBUG mode. We are also now going to log a message about slow startup
169                             //since 30 seconds is a long time to wait for your plugin to fail.
170                             final Plugin plugin = pluginsInEnablingState.iterator().next();
171                             final long remainingWait = Math.max(0, Math.round((singlePluginTimeout - currentTime) / 1000.0));
172 
173                             log.warn("Plugin '" + plugin + "' did not enable within " + (LAST_PLUGIN_WARN_TIMEOUT / 1000) + " seconds." + "The plugin should not take this long to enable. Will only attempt to load plugin for another '" + remainingWait + "' seconds.");
174                             singlePluginWarn = Long.MAX_VALUE;
175                         }
176                     }
177                     return pluginsInEnablingState.isEmpty();
178                 }
179 
180                 public String getWaitMessage()
181                 {
182                     return "Plugins that have yet to be enabled: " + pluginsInEnablingState;
183                 }
184 
185                 private boolean isAtlassianDevMode()
186                 {
187                     return Boolean.getBoolean(PluginUtils.ATLASSIAN_DEV_MODE);
188                 }
189             }, PluginUtils.getDefaultEnablingWaitPeriod(), TimeUnit.SECONDS, 1);
190 
191             // Disable any plugins that aren't enabled by now
192             if (!pluginsInEnablingState.isEmpty())
193             {
194                 final StringBuilder sb = new StringBuilder();
195                 for (final Plugin plugin : pluginsInEnablingState)
196                 {
197                     sb.append(plugin.getKey()).append(',');
198                     pluginController.disablePluginWithoutPersisting(plugin.getKey());
199                 }
200                 sb.deleteCharAt(sb.length() - 1);
201                 log.error("Unable to start the following plugins due to timeout while waiting for plugin to enable: " + sb.toString());
202             }
203         }
204     }
205 
206     /**
207      * Scans, recursively, to build a set of plugin dependencies for the target plugin
208      *
209      * @param plugin The plugin to scan
210      * @param dependentKeys The set of keys collected so far
211      */
212     private void scanDependencies(Plugin plugin, Set<String> dependentKeys)
213     {
214         dependentKeys.add(plugin.getKey());
215 
216         // Ensure dependent plugins are enabled first
217         for (String dependencyKey : plugin.getRequiredPlugins())
218         {
219             if (!dependentKeys.contains(dependencyKey) &&
220                     (pluginAccessor.getPlugin(dependencyKey) != null) &&
221                     !pluginAccessor.isPluginEnabled(dependencyKey))
222             {
223                 scanDependencies(pluginAccessor.getPlugin(dependencyKey), dependentKeys);
224             }
225         }
226     }
227 }