diff options
author | Uwe Stieber | 2015-02-25 18:10:01 +0000 |
---|---|---|
committer | Uwe Stieber | 2015-02-25 18:10:01 +0000 |
commit | efcaf61029872722fb0360e42442c59c7d6cb73e (patch) | |
tree | 59e76f2825e8bbbf429e875c2249fa0fe34b32f5 | |
parent | 1ebf9b8d8feab90f6a289aefe2226500b9ee4f13 (diff) | |
download | org.eclipse.tcf-efcaf61029872722fb0360e42442c59c7d6cb73e.tar.gz org.eclipse.tcf-efcaf61029872722fb0360e42442c59c7d6cb73e.tar.xz org.eclipse.tcf-efcaf61029872722fb0360e42442c59c7d6cb73e.zip |
Target Explorer: Bug 383349 - ChannelTraceListener.doLogMessage() takes ~10% of stepping time.
5 files changed, 332 insertions, 209 deletions
diff --git a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/META-INF/MANIFEST.MF b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/META-INF/MANIFEST.MF index 62793c287..01b17fc04 100644 --- a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/META-INF/MANIFEST.MF +++ b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/META-INF/MANIFEST.MF @@ -6,8 +6,9 @@ Bundle-Version: 1.3.0.qualifier Bundle-Activator: org.eclipse.tcf.te.tcf.log.core.activator.CoreBundleActivator Bundle-Vendor: %providerName Require-Bundle: org.eclipse.core.runtime;bundle-version="3.8.0", - org.eclipse.tcf.te.runtime;bundle-version="1.3.0", org.eclipse.tcf.core;bundle-version="1.3.0", + org.eclipse.tcf.te.runtime;bundle-version="1.3.0", + org.eclipse.tcf.te.runtime.concurrent;bundle-version="1.3.0", org.eclipse.tcf.te.tcf.core;bundle-version="1.3.0" Bundle-RequiredExecutionEnvironment: JavaSE-1.6 Bundle-ActivationPolicy: lazy diff --git a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/ChannelTraceListener.java b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/ChannelTraceListener.java index 71de49185..df4760c8c 100644 --- a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/ChannelTraceListener.java +++ b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/ChannelTraceListener.java @@ -1,5 +1,5 @@ /******************************************************************************* - * Copyright (c) 2011 - 2014 Wind River Systems, Inc. and others. All rights reserved. + * Copyright (c) 2011 - 2015 Wind River Systems, Inc. and others. All rights reserved. * This program and the accompanying materials are made available under the terms * of the Eclipse Public License v1.0 which accompanies this distribution, and is * available at http://www.eclipse.org/legal/epl-v10.html @@ -19,7 +19,10 @@ import org.eclipse.core.runtime.Assert; import org.eclipse.osgi.util.NLS; import org.eclipse.tcf.core.AbstractChannel.TraceListener; import org.eclipse.tcf.protocol.IChannel; +import org.eclipse.tcf.protocol.IPeer; +import org.eclipse.tcf.protocol.Protocol; import org.eclipse.tcf.services.IDiagnostics; +import org.eclipse.tcf.te.runtime.concurrent.util.ExecutorsUtil; import org.eclipse.tcf.te.tcf.core.util.JSONUtils; import org.eclipse.tcf.te.tcf.log.core.activator.CoreBundleActivator; import org.eclipse.tcf.te.tcf.log.core.events.MonitorEvent; @@ -31,7 +34,7 @@ import org.eclipse.tcf.te.tcf.log.core.manager.LogManager; /** * TCF logging channel trace listener implementation. */ -public class ChannelTraceListener implements TraceListener { +public final class ChannelTraceListener implements TraceListener { /** * Time format representing time with milliseconds. */ @@ -43,11 +46,11 @@ public class ChannelTraceListener implements TraceListener { public final DateFormat DATE_FORMAT = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS"); //$NON-NLS-1$ // Reference to the channel - private final IChannel channel; + /* default */ final IChannel channel; // The log name - private final String logname; + /* default */ final String logname; - private final boolean reverseReceived; + /* default */ final boolean reverseReceived; /** * Constructor. @@ -77,69 +80,117 @@ public class ChannelTraceListener implements TraceListener { * @see org.eclipse.tcf.core.AbstractChannel.TraceListener#onChannelClosed(java.lang.Throwable) */ @Override - public void onChannelClosed(Throwable error) { + public void onChannelClosed(final Throwable error) { + Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ + if (CoreBundleActivator.getTraceHandler().isSlotEnabled(0, ITracing.ID_TRACE_CHANNEL_TRACE_LISTENER)) { CoreBundleActivator.getTraceHandler().trace("TraceListener.onChannelClosed ( " + error + " )", //$NON-NLS-1$ //$NON-NLS-2$ ITracing.ID_TRACE_CHANNEL_TRACE_LISTENER, this); } - // Get the current time stamp - String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); + // Determine the remote peer from the channel + final IPeer peer = channel.getRemotePeer(); + if (peer == null) return; - String message = NLS.bind(Messages.ChannelTraceListener_channelClosed_message, - new Object[] { - date, - Integer.toHexString(channel.hashCode()), - error - }); + // Determine the date and time of the message before spawning to the log thread. + final String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); - // Get the file writer - FileWriter writer = LogManager.getInstance().getWriter(logname, channel); - if (writer != null) { - try { - writer.write(message); - writer.write("\n"); //$NON-NLS-1$ - writer.flush(); - } catch (IOException e) { - /* ignored on purpose */ - } - } + // This method is called in the TCF event dispatch thread. There + // is no need that the logging itself keeps the TCF event dispatch + // thread busy. Execute the logging itself in a separate thread but + // still maintain the order of the messages. + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + final String message = NLS.bind(Messages.ChannelTraceListener_channelClosed_message, + new Object[] { + date, + Integer.toHexString(channel.hashCode()), + error + }); + + // Get the file writer + FileWriter writer = LogManager.getInstance().getWriter(logname, peer); + if (writer != null) { + try { + writer.write(message); + writer.write("\n"); //$NON-NLS-1$ + writer.flush(); + } catch (IOException e) { + /* ignored on purpose */ + } + } - LogManager.getInstance().monitor(channel, MonitorEvent.Type.CLOSE, new MonitorEvent.Message('F', message)); + LogManager.getInstance().monitor(peer, MonitorEvent.Type.CLOSE, new MonitorEvent.Message('F', message)); + } + }); } /* (non-Javadoc) * @see org.eclipse.tcf.core.AbstractChannel.TraceListener#onMessageReceived(char, java.lang.String, java.lang.String, java.lang.String, byte[]) */ @Override - public void onMessageReceived(char type, String token, String service, String name, byte[] data) { + public void onMessageReceived(final char type, final String token, final String service, final String name, final byte[] data) { + Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ + if (CoreBundleActivator.getTraceHandler().isSlotEnabled(0, ITracing.ID_TRACE_CHANNEL_TRACE_LISTENER)) { CoreBundleActivator.getTraceHandler().trace("TraceListener.onMessageReceived ( " + type //$NON-NLS-1$ + ", " + token + ", " + service + ", " + name + ", ... )", //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ //$NON-NLS-4$ ITracing.ID_TRACE_CHANNEL_TRACE_LISTENER, this); } - doLogMessage(type, token, service, name, data, reverseReceived ? false : true); + // Determine the remote peer from the channel + final IPeer peer = channel.getRemotePeer(); + if (peer == null) return; + + // This method is called in the TCF event dispatch thread. There + // is no need that the logging itself keeps the TCF event dispatch + // thread busy. Execute the logging itself in a separate thread but + // still maintain the order of the messages. + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + doLogMessage(peer, type, token, service, name, data, reverseReceived ? false : true); + } + }); } /* (non-Javadoc) * @see org.eclipse.tcf.core.AbstractChannel.TraceListener#onMessageSent(char, java.lang.String, java.lang.String, java.lang.String, byte[]) */ @Override - public void onMessageSent(final char type, String token, String service, String name, byte[] data) { + public void onMessageSent(final char type, final String token, final String service, final String name, final byte[] data) { + Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ + if (CoreBundleActivator.getTraceHandler().isSlotEnabled(0, ITracing.ID_TRACE_CHANNEL_TRACE_LISTENER)) { CoreBundleActivator.getTraceHandler().trace("TraceListener.onMessageSent ( " + type //$NON-NLS-1$ + ", " + token + ", " + service + ", " + name + ", ... )", //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ //$NON-NLS-4$ ITracing.ID_TRACE_CHANNEL_TRACE_LISTENER, this); } - doLogMessage(type, token, service, name, data, reverseReceived ? true : false); + // Determine the remote peer from the channel + final IPeer peer = channel.getRemotePeer(); + if (peer == null) return; + + // This method is called in the TCF event dispatch thread. There + // is no need that the logging itself keeps the TCF event dispatch + // thread busy. Execute the logging itself in a separate thread but + // still maintain the order of the messages. + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + doLogMessage(peer, type, token, service, name, data, reverseReceived ? true : false); + } + }); } /** * Helper method to output the message to the logger. */ - private void doLogMessage(final char type, String token, String service, String name, byte[] data, boolean received) { + /* default */ void doLogMessage(final IPeer peer, final char type, String token, String service, String name, byte[] data, boolean received) { + Assert.isNotNull(peer); + Assert.isTrue(ExecutorsUtil.isExecutorThread(), "Illegal Thread Access"); //$NON-NLS-1$ + // Filter out the locator service messages boolean locatorEvents = CoreBundleActivator.getScopedPreferences().getBoolean(IPreferenceKeys.PREF_SHOW_LOCATOR_EVENTS); if (!locatorEvents && service != null && service.toLowerCase().equals("locator")) { //$NON-NLS-1$ @@ -168,7 +219,7 @@ public class ChannelTraceListener implements TraceListener { // Format the message final String message = formatMessage(type, token, service, name, args, received); // Get the file writer - FileWriter writer = LogManager.getInstance().getWriter(logname, channel); + FileWriter writer = LogManager.getInstance().getWriter(logname, peer); if (writer != null) { try { writer.write(message); @@ -178,13 +229,14 @@ public class ChannelTraceListener implements TraceListener { /* ignored on purpose */ } } - LogManager.getInstance().monitor(channel, MonitorEvent.Type.ACTIVITY, new MonitorEvent.Message(type, message)); + + LogManager.getInstance().monitor(peer, MonitorEvent.Type.ACTIVITY, new MonitorEvent.Message(type, message)); } /** * Format the trace message. */ - protected String formatMessage(char type, String token, String service, String name, String args, boolean received) { + private String formatMessage(char type, String token, String service, String name, String args, boolean received) { // Get the current time stamp String time = TIME_FORMAT.format(new Date(System.currentTimeMillis())); diff --git a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/ChannelTraceListenerManager.java b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/ChannelTraceListenerManager.java index cf521fee5..b355d6ce4 100644 --- a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/ChannelTraceListenerManager.java +++ b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/ChannelTraceListenerManager.java @@ -25,6 +25,7 @@ import org.eclipse.tcf.core.AbstractChannel; import org.eclipse.tcf.protocol.IChannel; import org.eclipse.tcf.protocol.IPeer; import org.eclipse.tcf.protocol.Protocol; +import org.eclipse.tcf.te.runtime.concurrent.util.ExecutorsUtil; import org.eclipse.tcf.te.tcf.log.core.activator.CoreBundleActivator; import org.eclipse.tcf.te.tcf.log.core.events.MonitorEvent; import org.eclipse.tcf.te.tcf.log.core.interfaces.IPreferenceKeys; @@ -35,7 +36,7 @@ import org.eclipse.tcf.te.tcf.log.core.manager.LogManager; /** * TCF logging channel trace listener manager implementation. */ -public class ChannelTraceListenerManager { +public final class ChannelTraceListenerManager { /** * Time format representing date and time with milliseconds. */ @@ -45,7 +46,7 @@ public class ChannelTraceListenerManager { private final Map<IChannel, AbstractChannel.TraceListener> listeners = new HashMap<IChannel, AbstractChannel.TraceListener>(); // The map of queued messaged per channel - private final Map<IChannel, List<String>> queued = new HashMap<IChannel, List<String>>(); + /* default */ final Map<IChannel, List<String>> queued = new HashMap<IChannel, List<String>>(); /* * Thread save singleton instance creation. @@ -74,7 +75,7 @@ public class ChannelTraceListenerManager { * @param channel The channel. Must not be <code>null</code>. * @param message A message or <code>null</code>. */ - public void onChannelOpened(String logname, IChannel channel, String message) { + public void onChannelOpened(final String logname, final IChannel channel, final String message) { Assert.isNotNull(channel); Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ @@ -88,6 +89,10 @@ public class ChannelTraceListenerManager { // The trace listeners can be accessed only via AbstractChannel if (!(channel instanceof AbstractChannel)) return; + // Determine the remote peer from the channel + final IPeer peer = channel.getRemotePeer(); + if (peer == null) return; + // Get the preference key if or if not logging is enabled boolean loggingEnabled = CoreBundleActivator.getScopedPreferences().getBoolean(IPreferenceKeys.PREF_LOGGING_ENABLED); // If false, we are done here and wont create any console or trace listener. @@ -103,40 +108,52 @@ public class ChannelTraceListenerManager { // Remember the associated trace listener listeners.put(channel, traceListener); - // Log the channel opening - String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); - - String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelOpened_message, - new Object[] { - date, - Integer.toHexString(channel.hashCode()), - message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ - }); - - // Get the file writer - FileWriter writer = LogManager.getInstance().getWriter(logname, channel); - if (writer != null) { - try { - writer.write("\n\n\n"); //$NON-NLS-1$ - - // Write the queued redirects - List<String> queue = queued.remove(channel); - if (queue != null) { - for (String m : queue) { - writer.write(m); + // Determine the date and time of the message before spawning to the log thread. + final String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); + + // This method is called in the TCF event dispatch thread. There + // is no need that the logging itself keeps the TCF event dispatch + // thread busy. Execute the logging itself in a separate thread but + // still maintain the order of the messages. + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelOpened_message, + new Object[] { + date, + Integer.toHexString(channel.hashCode()), + message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ + }); + + // Get the file writer + FileWriter writer = LogManager.getInstance().getWriter(logname, peer); + if (writer != null) { + try { + writer.write("\n\n\n"); //$NON-NLS-1$ + + // Get the queued messages + List<String> queue = queued.remove(channel); + + // Write the queued messages + if (queue != null) { + for (String m : queue) { + writer.write(m); + writer.write("\n"); //$NON-NLS-1$ + } + } + + // Write the opened message + writer.write(fullMessage); writer.write("\n"); //$NON-NLS-1$ + writer.flush(); + } catch (IOException e) { + /* ignored on purpose */ } } - - // Write the opened message - writer.write(fullMessage); - writer.write("\n"); //$NON-NLS-1$ - writer.flush(); - } catch (IOException e) { - /* ignored on purpose */ + LogManager.getInstance().monitor(peer, MonitorEvent.Type.OPEN, new MonitorEvent.Message('F', fullMessage)); } - } - LogManager.getInstance().monitor(channel, MonitorEvent.Type.OPEN, new MonitorEvent.Message('F', fullMessage)); + }); + } /** @@ -149,7 +166,7 @@ public class ChannelTraceListenerManager { * @param channel The channel. Must not be <code>null</code>. * @param message A message or <code>null</code>. */ - public void onChannelOpening(String logname, IChannel channel, String message) { + public void onChannelOpening(final String logname, final IChannel channel, final String message) { Assert.isNotNull(channel); Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ @@ -163,22 +180,31 @@ public class ChannelTraceListenerManager { // If false, we are done here and wont create any console or trace listener. if (!loggingEnabled) return; - // Log the channel opening - String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); - - String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelOpening_message, - new Object[] { - date, - Integer.toHexString(channel.hashCode()), - message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ - }); - - List<String> queue = queued.get(channel); - if (queue == null) { - queue = new ArrayList<String>(); - queued.put(channel, queue); - } - queue.add(fullMessage); + // Determine the date and time of the message before spawning to the log thread. + final String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); + + // This method is called in the TCF event dispatch thread. There + // is no need that the logging itself keeps the TCF event dispatch + // thread busy. Execute the logging itself in a separate thread but + // still maintain the order of the messages. + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelOpening_message, + new Object[] { + date, + Integer.toHexString(channel.hashCode()), + message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ + }); + + List<String> queue = queued.get(channel); + if (queue == null) { + queue = new ArrayList<String>(); + queued.put(channel, queue); + } + queue.add(fullMessage); + } + }); } /** @@ -188,7 +214,7 @@ public class ChannelTraceListenerManager { * @param channel The channel. Must not be <code>null</code>. * @param message A message or <code>null</code>. */ - public void onChannelRedirected(String logname, IChannel channel, String message) { + public void onChannelRedirected(final String logname, final IChannel channel, final String message) { Assert.isNotNull(channel); Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ @@ -202,22 +228,31 @@ public class ChannelTraceListenerManager { // If false, we are done here and wont create any console or trace listener. if (!loggingEnabled) return; - // Log the channel opening - String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); - - String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelRedirected_message, - new Object[] { - date, - Integer.toHexString(channel.hashCode()), - message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ - }); - - List<String> queue = queued.get(channel); - if (queue == null) { - queue = new ArrayList<String>(); - queued.put(channel, queue); - } - queue.add(fullMessage); + // Determine the date and time of the message before spawning to the log thread. + final String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); + + // This method is called in the TCF event dispatch thread. There + // is no need that the logging itself keeps the TCF event dispatch + // thread busy. Execute the logging itself in a separate thread but + // still maintain the order of the messages. + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelRedirected_message, + new Object[] { + date, + Integer.toHexString(channel.hashCode()), + message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ + }); + + List<String> queue = queued.get(channel); + if (queue == null) { + queue = new ArrayList<String>(); + queued.put(channel, queue); + } + queue.add(fullMessage); + } + }); } /** @@ -227,7 +262,7 @@ public class ChannelTraceListenerManager { * @param channel The channel. Must not be <code>null</code>. * @param message A message or <code>null</code>. */ - public void onChannelServices(String logname, IChannel channel, String message) { + public void onChannelServices(final String logname, final IChannel channel, final String message) { Assert.isNotNull(channel); Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ @@ -241,22 +276,31 @@ public class ChannelTraceListenerManager { // If false, we are done here and wont create any console or trace listener. if (!loggingEnabled) return; - // Log the channel opening - String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); - - String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelServices_message, - new Object[] { - date, - Integer.toHexString(channel.hashCode()), - message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ - }); - - List<String> queue = queued.get(channel); - if (queue == null) { - queue = new ArrayList<String>(); - queued.put(channel, queue); - } - queue.add(fullMessage); + // Determine the date and time of the message before spawning to the log thread. + final String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); + + // This method is called in the TCF event dispatch thread. There + // is no need that the logging itself keeps the TCF event dispatch + // thread busy. Execute the logging itself in a separate thread but + // still maintain the order of the messages. + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelServices_message, + new Object[] { + date, + Integer.toHexString(channel.hashCode()), + message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ + }); + + List<String> queue = queued.get(channel); + if (queue == null) { + queue = new ArrayList<String>(); + queued.put(channel, queue); + } + queue.add(fullMessage); + } + }); } /** @@ -266,7 +310,7 @@ public class ChannelTraceListenerManager { * @param channel The channel. Must not be <code>null</code>. * @param message A message or <code>null</code>. */ - public void onMark(String logname, IChannel channel, String message) { + public void onMark(final String logname, final IChannel channel, final String message) { Assert.isNotNull(channel); Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ @@ -277,33 +321,46 @@ public class ChannelTraceListenerManager { ITracing.ID_TRACE_CHANNEL_TRACE_LISTENER, this); } + // Determine the remote peer from the channel + final IPeer peer = channel.getRemotePeer(); + if (peer == null) return; + // Get the preference key if or if not logging is enabled boolean loggingEnabled = CoreBundleActivator.getScopedPreferences().getBoolean(IPreferenceKeys.PREF_LOGGING_ENABLED); // If false, we are done here and wont create any console or trace listener. if (!loggingEnabled) return; - // Log the channel opening - String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); - - String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelMark_message, - new Object[] { - date, - Integer.toHexString(channel.hashCode()), - message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ - }); - - // Get the file writer - FileWriter writer = LogManager.getInstance().getWriter(logname, channel); - if (writer != null) { - try { - // Write the message - writer.write(fullMessage); - writer.write("\n"); //$NON-NLS-1$ - writer.flush(); - } catch (IOException e) { - /* ignored on purpose */ + // Determine the date and time of the message before spawning to the log thread. + final String date = DATE_FORMAT.format(new Date(System.currentTimeMillis())); + + // This method is called in the TCF event dispatch thread. There + // is no need that the logging itself keeps the TCF event dispatch + // thread busy. Execute the logging itself in a separate thread but + // still maintain the order of the messages. + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + String fullMessage = NLS.bind(Messages.ChannelTraceListener_channelMark_message, + new Object[] { + date, + Integer.toHexString(channel.hashCode()), + message != null ? "(" + message.trim() + ")" : "" //$NON-NLS-1$ //$NON-NLS-2$ //$NON-NLS-3$ + }); + + // Get the file writer + FileWriter writer = LogManager.getInstance().getWriter(logname, peer); + if (writer != null) { + try { + // Write the message + writer.write(fullMessage); + writer.write("\n"); //$NON-NLS-1$ + writer.flush(); + } catch (IOException e) { + /* ignored on purpose */ + } + } } - } + }); } /** @@ -316,8 +373,13 @@ public class ChannelTraceListenerManager { Assert.isNotNull(channel); Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ - // Remove the queued messages - queued.remove(channel); + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + // Remove the queued messages + queued.remove(channel); + } + }); // The trace listeners can be accessed only via AbstractChannel if (!(channel instanceof AbstractChannel)) return; @@ -325,6 +387,8 @@ public class ChannelTraceListenerManager { // Remove the trace listener if any final AbstractChannel.TraceListener traceListener = listeners.remove(channel); if (traceListener != null) { + // Removal needs to happen asynchronous is another dispatch cycle, + // otherwise the closed event is not logged. Protocol.invokeLater(new Runnable() { @Override public void run() { diff --git a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/EventListener.java b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/EventListener.java index 585f4e990..49802ca30 100644 --- a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/EventListener.java +++ b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/internal/listener/EventListener.java @@ -14,7 +14,9 @@ import java.util.EventObject; import org.eclipse.core.runtime.Assert; import org.eclipse.core.runtime.PlatformObject; import org.eclipse.tcf.protocol.IChannel; +import org.eclipse.tcf.protocol.IPeer; import org.eclipse.tcf.protocol.Protocol; +import org.eclipse.tcf.te.runtime.concurrent.util.ExecutorsUtil; import org.eclipse.tcf.te.runtime.interfaces.events.IEventFireDelegate; import org.eclipse.tcf.te.runtime.interfaces.events.IEventListener; import org.eclipse.tcf.te.runtime.interfaces.properties.IPropertiesContainer; @@ -47,7 +49,7 @@ public final class EventListener extends PlatformObject implements IEventListene String type = ((ChannelEvent)event).getType(); IPropertiesContainer data = ((ChannelEvent)event).getData(); - String message = data != null ? data.getStringProperty(ChannelEvent.PROP_MESSAGE) : null; + final String message = data != null ? data.getStringProperty(ChannelEvent.PROP_MESSAGE) : null; String logname = data != null ? data.getStringProperty(ChannelEvent.PROP_LOG_NAME) : null; if (logname != null) logname = LogManager.getInstance().makeValid(logname); @@ -68,7 +70,22 @@ public final class EventListener extends PlatformObject implements IEventListene ChannelTraceListenerManager.getInstance().onMark(logname, channel, message); } else if (ChannelEvent.TYPE_CLOSE_WRITER.equals(type)) { - LogManager.getInstance().closeWriter(logname, channel, message); + // Determine the remote peer from the channel + final IPeer peer = channel.getRemotePeer(); + if (peer != null) { + final String lognameFinal = logname; + + // This method is called in the TCF event dispatch thread. There + // is no need that the logging itself keeps the TCF event dispatch + // thread busy. Execute the logging itself in a separate thread but + // still maintain the order of the messages. + ExecutorsUtil.execute(new Runnable() { + @Override + public void run() { + LogManager.getInstance().closeWriter(lognameFinal, peer, message); + } + }); + } } else if (ChannelEvent.TYPE_SERVICS.equals(type)) { ChannelTraceListenerManager.getInstance().onChannelServices(logname, channel, message); diff --git a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/manager/LogManager.java b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/manager/LogManager.java index e13e0efa4..f4c9b1897 100644 --- a/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/manager/LogManager.java +++ b/target_explorer/plugins/org.eclipse.tcf.te.tcf.log.core/src/org/eclipse/tcf/te/tcf/log/core/manager/LogManager.java @@ -1,5 +1,5 @@ /******************************************************************************* - * Copyright (c) 2011, 2014 Wind River Systems, Inc. and others. All rights reserved. + * Copyright (c) 2011, 2015 Wind River Systems, Inc. and others. All rights reserved. * This program and the accompanying materials are made available under the terms * of the Eclipse Public License v1.0 which accompanies this distribution, and is * available at http://www.eclipse.org/legal/epl-v10.html @@ -22,9 +22,8 @@ import org.eclipse.core.runtime.IPath; import org.eclipse.core.runtime.Path; import org.eclipse.core.runtime.Platform; import org.eclipse.osgi.util.NLS; -import org.eclipse.tcf.protocol.IChannel; import org.eclipse.tcf.protocol.IPeer; -import org.eclipse.tcf.protocol.Protocol; +import org.eclipse.tcf.te.runtime.concurrent.util.ExecutorsUtil; import org.eclipse.tcf.te.runtime.events.EventManager; import org.eclipse.tcf.te.tcf.log.core.activator.CoreBundleActivator; import org.eclipse.tcf.te.tcf.log.core.events.MonitorEvent; @@ -75,6 +74,8 @@ public final class LogManager { /** * Dispose the log manager instance. + * <p> + * Note: This method is callable from every thread. */ public void dispose() { // Close all still open file writer instances @@ -126,19 +127,21 @@ public final class LogManager { /** * Returns the file writer instance to use for the given channel. + * <p> + * Note: This method is callable from the executor thread only. * * @param logname The log name or <code>null</code>. - * @param channel The channel. Must not be <code>null</code>. + * @param peer The peer. Must not be <code>null</code>. * @return The file writer instance or <code>null</code>. */ - public FileWriter getWriter(String logname, IChannel channel) { - Assert.isNotNull(channel); - Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ + public FileWriter getWriter(String logname, IPeer peer) { + Assert.isNotNull(peer); + Assert.isTrue(ExecutorsUtil.isExecutorThread(), "Illegal Thread Access"); //$NON-NLS-1$ // Before looking up the writer, check the file limits - checkLimits(logname, channel); + checkLimits(logname, peer); - if (logname == null) logname = getLogName(channel); + if (logname == null) logname = getLogName(peer); FileWriter writer = logname != null ? fileWriterMap.get(logname) : null; if (writer == null && logname != null) { // Create the writer @@ -159,17 +162,19 @@ public final class LogManager { /** * Close the writer instance used for the given channel. + * <p> + * Note: This method is callable from the executor thread only. * * @param logname The log name or <code>null</code>. - * @param channel The channel. Must not be <code>null</code>. + * @param peer The peer. Must not be <code>null</code>. * @param message The last message to write or <code>null</code>. */ - public void closeWriter(String logname, IChannel channel, String message) { - Assert.isNotNull(channel); - Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ + public void closeWriter(String logname, IPeer peer, String message) { + Assert.isNotNull(peer); + Assert.isTrue(ExecutorsUtil.isExecutorThread(), "Illegal Thread Access"); //$NON-NLS-1$ // Remove the writer from the map - if (logname == null) logname = getLogName(channel); + if (logname == null) logname = getLogName(peer); FileWriter writer = logname != null ? fileWriterMap.remove(logname) : null; if (writer != null) { try { @@ -192,54 +197,37 @@ public final class LogManager { } /** - * Returns the log file base name for the given channel. - * - * @param channel The channel. Must not be <code>null</code>. - * @return The log file base name. - */ - public String getLogName(IChannel channel) { - Assert.isNotNull(channel); - Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ - - String logName = null; - - IPeer peer = channel.getRemotePeer(); - if (peer != null) logName = getLogName(peer); - - return logName; - } - - /** * Returns the log file base name for the given peer. + * <p> + * Note: This method is callable from every thread. * - * @param channel The channel. Must not be <code>null</code>. + * @param peer The peer. Must not be <code>null</code>. * @return The log file base name. */ public String getLogName(IPeer peer) { Assert.isNotNull(peer); - Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ String logName = null; - // Get the peer name - logName = peer.getName(); + // Get the peer name + logName = peer.getName(); - if (logName != null) { - // Get the peer host IP address - String ip = peer.getAttributes().get(IPeer.ATTR_IP_HOST); - // Fallback: The peer id - if (ip == null || "".equals(ip.trim())) { //$NON-NLS-1$ - ip = peer.getID(); - } + if (logName != null) { + // Get the peer host IP address + String ip = peer.getAttributes().get(IPeer.ATTR_IP_HOST); + // Fallback: The peer id + if (ip == null || "".equals(ip.trim())) { //$NON-NLS-1$ + ip = peer.getID(); + } - // Append the peer host IP address - if (ip != null && !"".equals(ip.trim())) { //$NON-NLS-1$ - logName += " " + ip.trim(); //$NON-NLS-1$ - } + // Append the peer host IP address + if (ip != null && !"".equals(ip.trim())) { //$NON-NLS-1$ + logName += " " + ip.trim(); //$NON-NLS-1$ + } - // Unify name and replace all undesired characters with '_' - logName = makeValid(logName); - } + // Unify name and replace all undesired characters with '_' + logName = makeValid(logName); + } return logName; } @@ -247,6 +235,8 @@ public final class LogManager { /** * Replaces a set of predefined patterns with underscore to * make a valid name. + * <p> + * Note: This method is callable from every thread. * * @param name The name. Must not be <code>null</code>. * @return The modified name. @@ -262,6 +252,8 @@ public final class LogManager { /** * Returns the log directory. + * <p> + * Note: This method is callable from every thread. * * @return The log directory. */ @@ -310,13 +302,13 @@ public final class LogManager { * Checks the limits set by the preferences. * * @param logname The log name or <code>null</code>. - * @param channel The channel. Must not be <code>null</code>. + * @param peer The peer. Must not be <code>null</code>. * @return The checked file writer instance. */ - private void checkLimits(String logname, IChannel channel) { - Assert.isNotNull(channel); + private void checkLimits(String logname, IPeer peer) { + Assert.isNotNull(peer); - String logName = getLogName(channel); + String logName = getLogName(peer); if (logName != null && !"".equals(logName.trim())) { //$NON-NLS-1$ IPath path = getLogDir(); if (path != null) { @@ -328,7 +320,7 @@ public final class LogManager { // Max log file size reached -> cycle files // If there is an active writer, flush and close the writer - closeWriter(logname, channel, null); + closeWriter(logname, peer, null); // Determine if the maximum number of files in the cycle has been reached File maxFileInCycle = path.append(logName + "_" + maxInCycle + ".log").toFile(); //$NON-NLS-1$ //$NON-NLS-2$ @@ -379,15 +371,15 @@ public final class LogManager { /** * Sends an event to the monitor signaling the given message and type. * - * @param channel The channel. Must not be <code>null</code>. + * @param peer The peer. Must not be <code>null</code>. * @param type The message type. Must not be <code>null</code>. * @param message The message. Must not be <code>null</code>. */ - public void monitor(IChannel channel, MonitorEvent.Type type, MonitorEvent.Message message) { - Assert.isNotNull(channel); + public void monitor(IPeer peer, MonitorEvent.Type type, MonitorEvent.Message message) { + Assert.isNotNull(peer); Assert.isNotNull(type); Assert.isNotNull(message); - Assert.isTrue(Protocol.isDispatchThread(), "Illegal Thread Access"); //$NON-NLS-1$ + Assert.isTrue(ExecutorsUtil.isExecutorThread(), "Illegal Thread Access"); //$NON-NLS-1$ // If monitoring is not enabled, return immediately if (!CoreBundleActivator.getScopedPreferences().getBoolean(IPreferenceKeys.PREF_MONITOR_ENABLED)) { @@ -395,11 +387,8 @@ public final class LogManager { } // The source of a monitor event is the peer. - IPeer peer = channel.getRemotePeer(); - if (peer != null) { - MonitorEvent event = new MonitorEvent(peer, type, message); - EventManager.getInstance().fireEvent(event); - } + MonitorEvent event = new MonitorEvent(peer, type, message); + EventManager.getInstance().fireEvent(event); } } |