evt dispatch thread slaughter


#1

Hi all,

I've just noticed an interesting event while chatting through the SIP
Communicator. After writing a message and hitting the send button,
nothing happened (apart from the exception at the end of the mail). My
message remained in the editable area of the chat window, while it
appears that my interlocutor actually received it. Re-hitting the send
button multiple times produced the same result.

After a short investigation it appears that this was the result of three
distinct problems. One of them concerns the history service impl,
another one is about the UI and the third is coming from the icq
provider but could be considered more generic.

1. The history problem.
  I had previously exchanged cyrillic messages with that particular interlocutor (who is no other but Pavel). During our conversation Pavel tried various char sets looking for the one that would allow SIP Communicator to show his cyrillic writings. Some of these charsets however seem to have caused problems with the history service which is now unable to parse contents of the files where these messages were logged. (cf stack trace at the end of the message)

2. The UI problem.
  This one is pretty obvious. The exception reached the UI (this was luck though since the provider might have decided to dispatch the send event in another thread) but since it was a simple RuntimeException, it got through the catch clauses and the user did not get notified of the failure.

3. The third (generic) problem.
  When I try to send a message to Pavel, the history service would get the SentMessageEvent and try to log it. It would open Pavel's log file and ... fail with the exception pasted at the bottom. This exception would surface up to the event dispatch method that delivered the message event and break its execution. Since the history service has registered its listener prior to the UI, the GUI service impl won't get the message sent event and will leave behave as if nothing happened.

We'd, obviously need to dig into the history issue and Yana, guess you could add a generic error handler on your thread group (or I think you could register one with Swing). Resolving these two however won't be enough.

I am beginning to think that we'd need to go over all fireXxx() methods
in the communicator and add try/catch clauses around the statements that
call the listener methods. In a modular application such as the SIP
Communicator, it is quite possible for plugins to introduce bugs and
throw exceptions from their callback methods, and it should be our
responsibility to gracefully handle them and don't let them cause much
trouble.

I am not sure which is the best and fastest way to do this (Simply try catch and log might be a bit too simple ...). If anyone
has a reference to a state-of-the-art event dispatch class published
somewhere on the net, it'd be nice to point us to it. Otherwise I'll
simply go through all fire statements and add catch-all-and-log clauses around all calls to listeners with a default of simply logging the exception.

Cheers
Emil

···

     [java] 13:21:10.219 FINE: impl.protocol.icq.ProtocolProviderServiceIcqImpl.sentOtherEvent() reveived ConversationEventInfo:net.kano.joustsim.oscar.oscar.service.icbm.TypingInfo@1b80c3
     [java] 13:21:10.221 FINE: impl.protocol.icq.ProtocolProviderServiceIcqImpl.sentMessage() sent message event
     [java] java.lang.RuntimeException: Error occured while parsing XML document.
     [java] at net.java.sip.communicator.impl.history.HistoryImpl.getDocumentForFile(HistoryImpl.java:230)
     [java] at net.java.sip.communicator.impl.history.HistoryWriterImpl.createNewDoc(HistoryWriterImpl.java:175)
     [java] at net.java.sip.communicator.impl.history.HistoryWriterImpl.addRecord(HistoryWriterImpl.java:89)
     [java] at net.java.sip.communicator.impl.history.HistoryWriterImpl.addRecord(HistoryWriterImpl.java:63)
     [java] at net.java.sip.communicator.impl.msghistory.MessageHistoryServiceImpl.writeMessage(MessageHistoryServiceImpl.java:452)
     [java] at net.java.sip.communicator.impl.msghistory.MessageHistoryServiceImpl.messageDelivered(MessageHistoryServiceImpl.java:429)
     [java] at net.java.sip.communicator.impl.protocol.icq.OperationSetBasicInstantMessagingIcqImpl.fireMessageEvent(OperationSetBasicInstantMessagingIcqImpl.java:459)
     [java] at net.java.sip.communicator.impl.protocol.icq.OperationSetBasicInstantMessagingIcqImpl.sendInstantMessage(OperationSetBasicInstantMessagingIcqImpl.java:232)
     [java] at net.java.sip.communicator.impl.gui.main.message.ChatSendPanel.actionPerformed(ChatSendPanel.java:100)
     [java] at javax.swing.AbstractButton.fireActionPerformed(AbstractButton.java:1786)
     [java] at javax.swing.AbstractButton$ForwardActionEvents.actionPerformed(AbstractButton.java:1839)
     [java] at javax.swing.DefaultButtonModel.fireActionPerformed(DefaultButtonModel.java:420)
     [java] at javax.swing.DefaultButtonModel.setPressed(DefaultButtonModel.java:258)
     [java] at javax.swing.AbstractButton.doClick(AbstractButton.java:289)
     [java] at javax.swing.AbstractButton.doClick(AbstractButton.java:269)
     [java] at net.java.sip.communicator.impl.gui.main.message.ChatPanel.sendMessage(ChatPanel.java:571)
     [java] at net.java.sip.communicator.impl.gui.main.message.ChatWindow$SendMessageAction.actionPerformed(ChatWindow.java:580)
     [java] at javax.swing.SwingUtilities.notifyAction(SwingUtilities.java:1530)
     [java] at javax.swing.JComponent.processKeyBinding(JComponent.java:2438)
     [java] at javax.swing.JComponent.processKeyBindings(JComponent.java:2484)
     [java] at javax.swing.JComponent.processKeyEvent(JComponent.java:2401)
     [java] at java.awt.Component.processEvent(Component.java:4909)
     [java] at java.awt.Container.processEvent(Container.java:1569)
     [java] at java.awt.Component.dispatchEventImpl(Component.java:3615)
     [java] at java.awt.Container.dispatchEventImpl(Container.java:1627)
     [java] at java.awt.Component.dispatchEvent(Component.java:3477)
     [java] at java.awt.KeyboardFocusManager.redispatchEvent(KeyboardFocusManager.java:1713)
     [java] at java.awt.DefaultKeyboardFocusManager.dispatchKeyEvent(DefaultKeyboardFocusManager.java:627)
     [java] at java.awt.DefaultKeyboardFocusManager.preDispatchKeyEvent(DefaultKeyboardFocusManager.java:831)
     [java] at java.awt.DefaultKeyboardFocusManager.typeAheadAssertions(DefaultKeyboardFocusManager.java:741)
     [java] at java.awt.DefaultKeyboardFocusManager.dispatchEvent(DefaultKeyboardFocusManager.java:592)
     [java] at java.awt.Component.dispatchEventImpl(Component.java:3506)
     [java] at java.awt.Container.dispatchEventImpl(Container.java:1627)
     [java] at java.awt.Window.dispatchEventImpl(Window.java:1606)
     [java] at java.awt.Component.dispatchEvent(Component.java:3477)
     [java] at java.awt.EventQueue.dispatchEvent(EventQueue.java:480)
     [java] at java.awt.EventDispatchThread.pumpOneEventForHierarchy(EventDispatchThread.java:201)
     [java] at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:151)
     [java] at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:145)
     [java] at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:137)
     [java] at java.awt.EventDispatchThread.run(EventDispatchThread.java:100)
     [java] Caused by: org.xml.sax.SAXParseException: Illegal XML character 
     [java] at org.apache.crimson.parser.Parser2.fatal(Parser2.java:3376)
     [java] at org.apache.crimson.parser.Parser2.fatal(Parser2.java:3370)
     [java] at org.apache.crimson.parser.Parser2.surrogatesToCharTmp(Parser2.java:2677)
     [java] at org.apache.crimson.parser.Parser2.maybeReferenceInContent(Parser2.java:2611)
     [java] at org.apache.crimson.parser.Parser2.content(Parser2.java:2017)
     [java] at org.apache.crimson.parser.Parser2.maybeElement(Parser2.java:1691)
     [java] at org.apache.crimson.parser.Parser2.content(Parser2.java:1963)
     [java] at org.apache.crimson.parser.Parser2.maybeElement(Parser2.java:1691)
     [java] at org.apache.crimson.parser.Parser2.content(Parser2.java:1963)
     [java] at org.apache.crimson.parser.Parser2.maybeElement(Parser2.java:1691)
     [java] at org.apache.crimson.parser.Parser2.parseInternal(Parser2.java:667)
     [java] at org.apache.crimson.parser.Parser2.parse(Parser2.java:337)
     [java] at org.apache.crimson.parser.XMLReaderImpl.parse(XMLReaderImpl.java:448)
     [java] at org.apache.crimson.jaxp.DocumentBuilderImpl.parse(DocumentBuilderImpl.java:185)
     [java] at javax.xml.parsers.DocumentBuilder.parse(DocumentBuilder.java:151)
     [java] at net.java.sip.communicator.impl.history.HistoryImpl.getDocumentForFile(HistoryImpl.java:227)
     [java] ... 40 more