sailfin
  1. sailfin
  2. SAILFIN-1877

"Cant find matching transactions" msg observed in the server log

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.0
    • Fix Version/s: b26
    • Component/s: sip_container
    • Labels:
      None
    • Environment:

      Operating System: All
      Platform: All

      Description

      ******************************************************************************************************

      • Template v0.1 ( 05/01/08 )
      • Sailfin Stress test issue
        ******************************************************************************************************
        Sailfin Build : 23
        Cluster size : 10
        Happens in a single instance (y/n) ? : NA
        Test id : st2_4_presence_subscribe-refresh
        Location of the test : as-telco-sqe/stress-ws/presence
        JDK version : 1.6.0_12
        CLB used : Yes
        HW LB used : Yes.
        SSR: Enabled

      sipp command :
      sipp -t t1 -sf st2_4_presence_subscribe-refresh-failure.xml -r 275 -m 200000 -d
      728000 -nd -trace_err -trace_screen -buff_size 33554432 -reconnect_close false
      -max_reconnect 10 -reconnect_sleep 3000 <sailfin_host:sip_port>

      *****************************************************************************

      • No failure involved.
      • "Cant find matching transaction" messages observed in the logs from the start
        of the run. ~2000 of them in the cluster over a 24*1 run.
      • These seem to be co-related with 2 other messages as shown below in a log
        snippet (one of the instance's logs will be attached):
        *******
        [#|2009-07-21T15:36:48.324+0530|INFO|sun-glassfish-comms-server2.0|javax.enterprise.system.container.sip|_ThreadID=32;_ThreadName=Thread-32;|Number
        of overdue ClientTransactions removed:1|#]

      [#|2009-07-21T15:36:48.329+0530|SEVERE|sun-glassfish-comms-server2.0|javax.enterprise.system.container.sip|_ThreadID=33;_ThreadName=SipContainer-serversWorkerThread-5060-2;_RequestID=6412b8af-29d5-41db-b00c-edba9ae48623;|"Cant
      find matching transaction - Terminating"|#]

      [#|2009-07-21T15:37:20.301+0530|WARNING|sun-glassfish-comms-server2.0|javax.enterprise.system.container.sip|_ThreadID=34;_ThreadName=Thread-36;_RequestID=386d3e52-e52d-42b4-a410-abf2cad0974a;|Transaction
      was null: z9hG4bK8a5245d66f49c5c7456dbbb554e580e08c96|#]
      *************

      The number of "Cant find...." and the "Transaction was null" messages seems to
      be equal to the number provided by the "Number of overdue ClientTransactions
      removed" message.
      Also, the "Transaction was null" message seems to appear 32 seconds after the
      "Cant find ..." message.

      • The SIPp screens do not show any errors and response times seem ok as well.

        Issue Links

          Activity

          Hide
          varunrupela added a comment -

          Created an attachment (id=1056)
          attached server log from one of the instances

          Show
          varunrupela added a comment - Created an attachment (id=1056) attached server log from one of the instances
          Hide
          varunrupela added a comment -

          added keyword

          Show
          varunrupela added a comment - added keyword
          Hide
          easarina added a comment -

          The same problem was reported in the SAILFIN-1869.

          Show
          easarina added a comment - The same problem was reported in the SAILFIN-1869 .
          Hide
          Scott Oaks added a comment -

          The root cause of this is because the transaction subsystem does not correctly
          track the length of time a transaction is alive.

          Periodically, the dialog cleaner calls TransactionManager.doScavenge, which
          searches all in-flight transactions and checks to see how long they have been
          alive by checking ct (the client transaction; ditto for server transaction):

          now > (ct.getTransactionStartTime() + MAX_TRANSACTION_LIFETIME)

          However, getTransactionStartTime always returns 0 because the initialization
          code in Transaction.<init> only runs if
          SipMonitoring.isEnabled(SipMonitoring.TRANSACTION_MANAGER) is true (which it
          usually isn't). So the transaction is always out of date and always removed.

          Show
          Scott Oaks added a comment - The root cause of this is because the transaction subsystem does not correctly track the length of time a transaction is alive. Periodically, the dialog cleaner calls TransactionManager.doScavenge, which searches all in-flight transactions and checks to see how long they have been alive by checking ct (the client transaction; ditto for server transaction): now > (ct.getTransactionStartTime() + MAX_TRANSACTION_LIFETIME) However, getTransactionStartTime always returns 0 because the initialization code in Transaction.<init> only runs if SipMonitoring.isEnabled(SipMonitoring.TRANSACTION_MANAGER) is true (which it usually isn't). So the transaction is always out of date and always removed.
          Hide
          Scott Oaks added a comment -

          ...

          Show
          Scott Oaks added a comment - ...
          Hide
          sankara added a comment -

          This issue is exposed by the fix to configuration of SIP monitoring. Previously
          SIP monitoring was always enabled and there isn't way to disable and recent fix
          made is configurable and disabled by default.
          Thanks Scott for investigating and finding out the cause. Integrated the change.
          Checking in Transaction.java;
          /cvs/sailfin/sip-stack/src/java/com/ericsson/ssa/sip/transaction/Transaction.java,v
          <-- Transaction.java
          new revision: 1.18; previous revision: 1.17

          Show
          sankara added a comment - This issue is exposed by the fix to configuration of SIP monitoring. Previously SIP monitoring was always enabled and there isn't way to disable and recent fix made is configurable and disabled by default. Thanks Scott for investigating and finding out the cause. Integrated the change. Checking in Transaction.java; /cvs/sailfin/sip-stack/src/java/com/ericsson/ssa/sip/transaction/Transaction.java,v <-- Transaction.java new revision: 1.18; previous revision: 1.17
          Hide
          sankara added a comment -
              • Issue 1878 has been marked as a duplicate of this issue. ***
          Show
          sankara added a comment - Issue 1878 has been marked as a duplicate of this issue. ***

            People

            • Assignee:
              sankara
              Reporter:
              varunrupela
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: