[sip-comm-dev] Re: [ice4j] r248 committed - Add some log outputs.


#1

Hey Seb,

Could you please update the ice4j lib in SC to include the logging
output. This should help us diagnose the problems that others have been
reporting here.

Cheers,
Emil

На 13.12.10 18:52, ice4j@googlecode.com написа:

···

Revision: 248
Author: seb@sip-communicator.org
Date: Mon Dec 13 09:20:13 2010
Log: Add some log outputs.
http://code.google.com/p/ice4j/source/detail?r=248

Modified:
  /trunk/src/org/ice4j/ice/Agent.java
  /trunk/src/org/ice4j/ice/CandidatePair.java
  /trunk/src/org/ice4j/ice/CheckList.java
  /trunk/src/org/ice4j/ice/Component.java
  /trunk/src/org/ice4j/ice/ConnectivityCheckClient.java
  /trunk/src/org/ice4j/ice/ConnectivityCheckServer.java
  /trunk/src/org/ice4j/ice/DefaultNominator.java

=======================================
--- /trunk/src/org/ice4j/ice/Agent.java Thu Dec 9 02:29:58 2010
+++ /trunk/src/org/ice4j/ice/Agent.java Mon Dec 13 09:20:13 2010
@@ -235,6 +235,7 @@
       */
      public IceMediaStream createMediaStream(String mediaStreamName)
      {
+ logger.info("Create media stream for " + mediaStreamName);
          IceMediaStream mediaStream
              = new IceMediaStream(Agent.this, mediaStreamName);

@@ -286,7 +287,14 @@

          Component component = stream.createComponent(transport);

+ logger.info("Create component " + component.toShortString());
+
          gatherCandidates(component, preferredPort, minPort, maxPort);
+
+ for(Candidate candidate : component.getLocalCandidates())
+ {
+ logger.info("\t" + candidate.getTransportAddress());
+ }

          /*
           * Lyubomir: After we've gathered the LocalCandidate for a
Component and
@@ -333,6 +341,9 @@
          throws IllegalArgumentException,
                 IOException
      {
+ logger.info("Gather candidates for component " +
+ component.toShortString());
+
          hostCandidateHarvester.harvest(
                  component,
                  preferredPort, minPort, maxPort);
@@ -359,6 +370,7 @@
      {
          synchronized(startLock)
          {
+ logger.info("Start ICE connectivity establishment");
              pruneNonMatchedStreams();
              initCheckLists();

@@ -532,6 +544,7 @@

          for(IceMediaStream stream : streams)
          {
+ logger.info("Init checklist for stream " + stream.getName());
              stream.setMaxCheckListSize(maxPerStreamSize);
              stream.initCheckList();
          }
@@ -1020,6 +1033,7 @@
              }
              else
              {
+ logger.fine("Receive STUN checks before our ICE has
started");
                  //we are not started yet so we'd better wait until we get
the
                  //remote candidates in case we are holding to a new PR one.
                  this.preDiscoveredPairsQueue.add(triggeredPair);
@@ -1164,7 +1178,6 @@

          Component parentComponent = pair.getParentComponent();
          IceMediaStream parentStream = parentComponent.getParentStream();
- //CheckList checkList = parentStream.getCheckList();

          //If the pair is not already nominated and if its parent component
          //does not already contain a nominated pair - nominate it.
@@ -1244,6 +1257,8 @@
              }
              else if(checkListState == CheckListState.COMPLETED)
              {
+ logger.info("CheckList of stream " + stream.getName() +
+ " is COMPLETED");
                  atLeastOneListSucceeded = true;
              }
          }
@@ -1256,12 +1271,14 @@
              {
                  if(getState() == IceProcessingState.RUNNING)
                  {
+ logger.info("ICE state is COMPLETED");
                      setState(IceProcessingState.COMPLETED);
                      scheduleTermination();
                  }
              }
              else
              {
+ logger.info("ICE state is FAILED");
                  terminate(IceProcessingState.FAILED);
              }
          }
@@ -1463,6 +1480,7 @@
                  }
              }

+ logger.info("ICE state is TERMINATED");
              terminate(IceProcessingState.TERMINATED);
          }
      }
@@ -1514,6 +1532,8 @@
       */
      public void free()
      {
+ logger.info("Free ICE agent");
+
          /*
           * Set the IceProcessingState#TERMINATED state on this Agent
unless it
           * is in a termination state already.

--- /trunk/src/org/ice4j/ice/CandidatePair.java Thu Nov 25 08:03:44 2010
+++ /trunk/src/org/ice4j/ice/CandidatePair.java Mon Dec 13 09:20:13 2010
@@ -417,6 +417,18 @@
              + "):\n\tLocalCandidate=" + getLocalCandidate()
              + "\n\tRemoteCandidate=" + getRemoteCandidate();
      }
+
+ /**
+ * Returns a short String representation of this
<tt>CandidatePair</tt>.
+ *
+ * @return a short String representation of the object.
+ */
+ public String toShortString()
+ {
+ return getLocalCandidate().getTransportAddress() + " -> " +
+ getRemoteCandidate().getTransportAddress() +
+ " (" + getParentComponent().toShortString() + ")";
+ }

      /**
       * A <tt>Comparator</tt> using the <tt>compareTo</tt> method of the

--- /trunk/src/org/ice4j/ice/CheckList.java Thu Nov 25 08:03:44 2010
+++ /trunk/src/org/ice4j/ice/CheckList.java Mon Dec 13 09:20:13 2010
@@ -8,6 +8,7 @@

  import java.beans.*;
  import java.util.*;
+import java.util.logging.*;

  /**
   * A check list is a list of <tt>CandidatePair</tt>s with a state (i.e. a
@@ -22,6 +23,12 @@
  public class CheckList
      extends Vector<CandidatePair>
  {
+ /**
+ * The logger.
+ */
+ private static final Logger logger =
+ Logger.getLogger(CheckList.class.getName());
+
      /**
       * A dummy serialization id.
       */
@@ -349,6 +356,10 @@
      {
          Component cmp = nominatedPair.getParentComponent();

+ logger.info("Selected pair for stream " +
+ cmp.toShortString() + ": " +
+ nominatedPair.toShortString());
+
          cmp.setSelectedPair(nominatedPair);

          Iterator<CandidatePair> pairsIter = iterator();

--- /trunk/src/org/ice4j/ice/Component.java Mon Dec 6 08:41:58 2010
+++ /trunk/src/org/ice4j/ice/Component.java Mon Dec 13 09:20:13 2010
@@ -206,6 +206,9 @@
       */
      public void addRemoteCandidate(Candidate candidate)
      {
+ logger.info("Add remote candidate for " + toShortString() + ": " +
+ candidate.getTransportAddress());
+
          synchronized(remoteCandidates)
          {
              remoteCandidates.add(candidate);
@@ -220,6 +223,9 @@
       */
      public void addUpdateRemoteCandidate(Candidate candidate)
      {
+ logger.info("Update remote candidate for " + toShortString()
+ ": " +
+ candidate.getTransportAddress());
+
          synchronized(remoteUpdateCandidates)
          {
              remoteUpdateCandidates.add(candidate);
@@ -426,6 +432,23 @@

          return buff.toString();
      }
+
+ /**
+ * Returns a short <tt>String</tt> representation of this
+ * <tt>Component</tt>.
+ *
+ * @return a short <tt>String</tt> representation of this
+ * <tt>Component</tt>.
+ */
+ public String toShortString()
+ {
+ StringBuffer buff
+ = new StringBuffer(parentStream.getName());
+ buff.append(".");
+ buff.append(componentID);
+
+ return buff.toString();
+ }

      /**
       * Computes the priorities of all <tt>Candidate</tt>s and then sorts
them

--- /trunk/src/org/ice4j/ice/ConnectivityCheckClient.java Mon Dec 6
08:41:58 2010
+++ /trunk/src/org/ice4j/ice/ConnectivityCheckClient.java Mon Dec 13
09:20:13 2010
@@ -75,6 +75,7 @@
                      .get(0)
                          .getCheckList();

+ logger.info("Start connectivity checks!");
          startChecks(firstCheckList);
      }

@@ -136,8 +137,12 @@
              //if we are the controlling agent then we need to indicate our
              //nominated pairs.
              if(candidatePair.isNominated())
+ {
+ logger.fine("Add USE-CANDIDATE in check for: " +
+ candidatePair.toShortString());
                  request.addAttribute(AttributeFactory
                                  .createUseCandidateAttribute());
+ }
          }
          else
          {
@@ -220,7 +225,7 @@
          if (!checkSymmetricAddresses(evt))
          {
              logger.fine("Received a non-symmetric response for pair: "
- + checkedPair +". Failing");
+ + checkedPair.toShortString() +". Failing");
              checkedPair.setStateFailed();
          }
          //handle error responses.
@@ -285,7 +290,11 @@
              //If there is not a pair in the valid list for each component
of the
              //media stream, the state of the check list is set to Failed.
              if ( !stream.validListContainsAllComponents())
+ {
+ logger.info("CheckList for stream " + stream.getName() +
+ " FAILED");
                  checkList.setState(CheckListState.FAILED);
+ }

              //For each frozen check list, the agent groups together all of
the
              //pairs with the same foundation, and for each group, sets the
@@ -327,6 +336,7 @@
          {
              logger.fine("Received a success response with no "
                              +"XOR_MAPPED_ADDRESS attribute.");
+ logger.info("Pair failed: " + checkedPair.toShortString());
              checkedPair.setStateFailed();
              return; //malformed error response
          }
@@ -375,6 +385,9 @@
              //remote candidates. This is not necessary; a valid pair will
be
              //generated from it momentarily
              validLocalCandidate = peerReflexiveCandidate;
+
+ logger.fine("Receive a peer-reflexive candidate: " +
+ peerReflexiveCandidate.getTransportAddress());
          }

          //check if the resulting valid pair was already in our check lists.
@@ -401,10 +414,14 @@
          //The agent sets the state of the pair that *generated* the check
to
          //Succeeded. Note that, the pair which *generated* the check may
be
          //different than the valid pair constructed above
+ logger.info("Pair succeeded: " + checkedPair.toShortString());
          checkedPair.setStateSucceeded();

          if(! validPair.isValid())
+ {
+ logger.info("Pair validated: " + validPair.toShortString());
              parentAgent.validatePair(validPair);
+ }

          //The agent changes the states for all other Frozen pairs for the
          //same media stream and same foundation to Waiting.
@@ -451,7 +468,11 @@
                  checkList.computeInitialCheckListPairStates();

              if (wasFrozen)
+ {
+ logger.info("Start checks for checkList of stream " +
+ stream.getName() + " that was frozen");
                  startChecks(checkList);
+ }
          }

          //If the agent was a controlling agent, and it had included a USE-
@@ -460,6 +481,8 @@
          if(parentAgent.isControlling()
                  && request.containsAttribute(Attribute.USE_CANDIDATE))
          {
+ logger.info("Nomination confirmed for pair: " +
+ validPair.toShortString());
              parentAgent.nominationConfirmed( validPair );
          }
          //If the agent is the controlled agent, the response may be the
result
@@ -469,7 +492,11 @@
          //the pair learned from the original request.
          else if(checkedPair.useCandidateReceived()
                   && ! checkedPair.isNominated())
+ {
+ logger.info("Nomination confirmed for pair: " +
+ validPair.toShortString());
              parentAgent.nominationConfirmed( checkedPair );
+ }
      }

      /**
@@ -542,7 +569,8 @@
          else
          {
              logger.fine("Received an unrecoverable error response for
pair "
- + pair + " will mark the pair as FAILED.");
+ + pair.toShortString() +
+ " will mark the pair as FAILED.");
              pair.setStateFailed();
          }
      }
@@ -559,8 +587,7 @@
      {
          CandidatePair pair = ((CandidatePair)event.getTransactionID()
                          .getApplicationData());
- logger.fine("timeout for pair=" + pair);
-
+ logger.info("timeout for pair: " + pair.toShortString() +",
failing.");
          pair.setStateFailed();
          updateCheckListAndTimerStates(pair);
      }
@@ -682,7 +709,11 @@
                                  = startCheckForPair(pairToCheck);

                              if(transactionID == null)
+ {
+ logger.info("Pair failed: " +
+ pairToCheck.toShortString());
                                  pairToCheck.setStateFailed();
+ }
                              else
                                   
pairToCheck.setStateInProgress(transactionID);
                          }

--- /trunk/src/org/ice4j/ice/ConnectivityCheckServer.java Mon Dec 6
08:41:58 2010
+++ /trunk/src/org/ice4j/ice/ConnectivityCheckServer.java Mon Dec 13
09:20:13 2010
@@ -146,6 +146,11 @@
          }
          catch (Exception e)
          {
+ logger.log(
+ Level.INFO,
+ "Failed to send " + response
+ + " through " + evt.getLocalAddress(),
+ e);
              //try to trigger a 500 response although if this one failed,
              //then chances are the 500 will fail too.
              throw new RuntimeException("Failed to send a response", e);

--- /trunk/src/org/ice4j/ice/DefaultNominator.java Tue May 18 00:23:41 2010
+++ /trunk/src/org/ice4j/ice/DefaultNominator.java Mon Dec 13 09:20:13 2010
@@ -8,6 +8,7 @@

  import java.beans.*;
  import java.util.*;
+import java.util.logging.*;

  /**
   * Implements ice4j internal nomination strategies.
@@ -17,6 +18,12 @@
  public class DefaultNominator
      implements PropertyChangeListener
  {
+ /**
+ * The logger.
+ */
+ private static Logger logger =
+ Logger.getLogger(DefaultNominator.class.getName());
+
      /**
       * The Agent that created us.
       */
@@ -91,6 +98,8 @@
           
if(IceMediaStream.PROPERTY_PAIR_VALIDATED.equals(evt.getPropertyName()))
          {
              CandidatePair validPair = (CandidatePair)evt.getSource();
+
+ logger.info("Nominate (first valid): " +
validPair.toShortString());
              parentAgent.nominate(validPair);
          }
      }
@@ -125,7 +134,11 @@
              {
                  CandidatePair pair = parentStream.getValidPair(component);
                  if(pair != null)
+ {
+ logger.info("Nominate (highest priority): " +
+ validPair.toShortString());
                      parentAgent.nominate(pair);
+ }
              }
          }
      }

---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: commits-help@sip-communicator.dev.java.net

--
Emil Ivov, Ph.D. 67000 Strasbourg,
Project Lead France
SIP Communicator
emcho@sip-communicator.org PHONE: +33.1.77.62.43.30
http://sip-communicator.org FAX: +33.1.77.62.47.31

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@sip-communicator.dev.java.net
For additional commands, e-mail: dev-help@sip-communicator.dev.java.net