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