Want to protect your cyber security and still get fast solutions? Ask a secure question today.Go Premium

x
  • Status: Solved
  • Priority: Medium
  • Security: Public
  • Views: 229
  • Last Modified:

Synchronization Problem

The following is a long explanation of a synchronization issue.  The main questions (at the end) are:
Has this been documented or experienced by others, and are there ways for thread control that can be used to replace synchronization?

I've encountered a problem with Java synchronization (I'm currently using JDK 1.3.1).  Here's a snippet of the Java class:

public class MasterGenerator
{
      private static String statusSyncObject = "";

      public boolean updateBook(Hashtable sessionHash, int status) throws DatabaseException
         {
                    Log.log(Log.DEBUG,"Inside MasterGenerator notify()");


            Log.log(Log.DEBUG,"Before sync block in updateBook");

            synchronized(statusSyncObject)
                {
                  Log.log(Log.DEBUG,"start of sync block in updateBook");

                  ServerSession session = (ReportBookServerSessionImpl)sessionHash.get(rbkey);

                  session.updateStatus(status);

                  Log.log(Log.DEBUG,"end of sync block in updateBook");
            }
      }
.
.
.
}

The application is usually very active, and a hundred or so instances of this class can be created with the updateBook method called every second.  Then the application just hangs (the majority of the application, that is, the part that is dependent on this routine).  My first suspicion was a synchronization problem; maybe with a deadlock, but in the code there was no deadlock possible.  Then I began to do timings within synchronization blocks, and with a heavy load what I found was that the handling of synchronization was very slow, taking many minutes between the exit of one thread and the start of the next.  Finally, I put logging statements in every synchronized block, like above, and waited for it to happen again.  The normal log would should something like this:

Inside MasterGenerator notify()
Before sync block in updateBook
start of sync block in updateBook
end of sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
start of sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
end of sync block in updateBook
start of sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
end of sync block in updateBook
...

which is perfectly okay. This pattern would repeat for days without problems, making up 99%+ of what is seen.  Then when the application hung again, I looked at the log, and the ending showed basically this:

Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook

basically every thread is waiting to get in.  Looking at the two calls between the logs, there is really no particular point in the code that should or could get stuck at (errors yes, but not stuck).   In addition, I put logs in those methods which shows them getting in and out of them (and in between).  But what's REALLY curious is before this pattern of hanging, I see something like this in the log file:

Inside MasterGenerator notify()
Before sync block in updateBook
start of sync block in updateBook
start of sync block in updateBook
end of sync block in updateBook
end of sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
Inside MasterGenerator notify()
Before sync block in updateBook
start of sync block in updateBook
start of sync block in updateBook
end of sync block in updateBook
end of sync block in updateBook
start of sync block in updateBook
start of sync block in updateBook
end of sync block in updateBook
end of sync block in updateBook

Basically this should never happen - there should never be two starts in a row (without an end in between), but this duplicate happened regularly for a little while in the log before hanging permanently.  By the way, the Log class is a simple custom class that opens a log file, appends to it, and closes the file for every log request.  The Log class itself uses a static synchronization method for those three steps plus a short sleep delay at the end of the method, so every thread that is logging will have to wait its turn.  Since it also uses synchronization, there is no guarantee that the log requests will appear in the order they were received, but it usually happens this way from my experience.  In any case, in this particular situation, the abnormality (double starts and ends) happened too regularly to be explained by random log synchronization timing.  I should also point on that the log file contains many other logs (I've only shown the logs from the code snippet), and logging did continue for other parts of the application where things were not hanging.

I am wondering whether this synchronization problem has been documented, or has anyone encountered a similar problem under heavy loads.  Also, is there another way for thread control without the use of synchronization?  Thanks in Advance.


0
jove
Asked:
jove
  • 2
  • 2
  • 2
  • +2
1 Solution
 
kylarCommented:
Can you post the Log class/method too?

Kylar
0
 
kylarCommented:
Is one of the methods:

ServerSession session = (ReportBookServerSessionImpl)sessionHash.get(rbkey);

session.updateStatus(status);

possibly throwing? Java will give up the syncronization lock as soon as the code goes outside the scope of the lock (either by ending the run or by exception).

Kylar
0
 
joveAuthor Commented:
Neither of those methods will throw exceptions up here - they're caught in try-catch blocks in their respective methods.

Here's a snippet of the Log class:

public static void log(int pMsgType, Object pMsgObject)
{
  if (pMsgType > minSeverity)
     return;
  ...
  writeLog(pMsgType, msg, logFileName, recordSource, showMilliSeconds);
}

private static synchronized void writeLog(int pMsgType, String msg, String pLogFileName, String pRecordSource, boolean pMilli)
  {
               
        PrintWriter p = null;
        FileOutputStream fos = null;

        if (pLogFileName.equals(""))
        {
         System.out.println(msg);
            return;
     }


        try
        {
            fos = new FileOutputStream(pLogFileName, true);
            p = new PrintWriter( fos );
        }
        catch( IOException e )
        {
                     System.err.println("LogFile: Exception: " + e.getMessage());
            try
            {
                if (p != null)
                    p.close();
                if (fos != null)
                    fos.close();
            }
            catch (IOException ioe) {}
           
            return;
        }

        try
        {
                  String msgHdr = buildMsgHeader(pMsgType, pRecordSource, pMilli);

                  StringTokenizer strtok = new StringTokenizer(msg,"\n",false);
                  String token = "";

                  while (strtok.hasMoreElements())
                     {
                         token = strtok.nextToken();
                   p.print(msgHdr);
                   p.println(token);
                     }
               
            p.flush();
              }
        finally
        {
            try
            {
                if (p != null)
                    p.close();
                if (fos != null)
                    fos.close();
            }
            catch (IOException ioe) {}

        }

    }
0
Industry Leaders: We Want Your Opinion!

We value your feedback.

Take our survey and automatically be enter to win anyone of the following:
Yeti Cooler, Amazon eGift Card, and Movie eGift Card!

 
objectsCommented:
Maybe an exception other that an IOException.
Plus you don't print out the exception in the second try/catch so if an exception was being thrown (resulting in nothing being written to the log) then you would not know about it.

I'd suggest printing out any exceptions that are caught plus something like the following jic:

  synchronized(statusSyncObject)
  {
     try
     {
        Log.log(Log.DEBUG,"start of sync block in updateBook");

        ServerSession session = (ReportBookServerSessionImpl)sessionHash.get(rbkey);

        session.updateStatus(status);
     }
     catch (Exception ex)
     {
        System.err.println(ex);
     }
     finally
     {
        Log.log(Log.DEBUG,"end of sync block in updateBook");
     }
  }
0
 
objectsCommented:
0
 
Venci75Commented:
are you sure that ther is no call to a wait() method in any of the:
Log.log()
ReportBookServerSessionImpl.get();
ServerSession.updateStatus();

methods?    
0
 
joveAuthor Commented:
I'll put a try/catch block on the synchronized block, and add messaging on the catch portions of the logging.  I don't think that this is the root of the problem, but it's a good idea anyway.  There is no call to the wait() method anywhere in the code.
0
 
girionisCommented:
No comment has been added lately, so it's time to clean up this TA.
I will leave a recommendation in the Cleanup topic area that this
question is:

- points to objects

Please leave any comments here within the
next seven days.

PLEASE DO NOT ACCEPT THIS COMMENT AS AN ANSWER !

girionis
Cleanup Volunteer
0

Featured Post

VIDEO: THE CONCERTO CLOUD FOR HEALTHCARE

Modern healthcare requires a modern cloud. View this brief video to understand how the Concerto Cloud for Healthcare can help your organization.

  • 2
  • 2
  • 2
  • +2
Tackle projects and never again get stuck behind a technical roadblock.
Join Now