[jcifs] Another fix for Transport deadlock issue ?

[Dalton, Tim]

We tried using the 1.2.9 release of jcifs, but noticed throughput is significantly lower due to the new Transport.setupDiscoLock monitor. We were only experience the deadlock when a Transport experiences an IOException:

Found one Java-level deadlock:
=============================
"DniDeviceReaderJms-TDMS1_SAMBA49":
  waiting to lock monitor 0x080b89ec (object 0x47320060, a java.util.HashMap),
  which is held by "DniDeviceReaderJms-TDMS1_SAMBA27"
"DniDeviceReaderJms-TDMS1_SAMBA27":
  waiting to lock monitor 0x5190724c (object 0x47320088, a jcifs.smb.SmbTransport),
  which is held by "DniDeviceReaderJms-TDMS1_SAMBA49"

Java stack information for the threads listed above:
===================================================
"DniDeviceReaderJms-TDMS1_SAMBA49":
        at jcifs.util.transport.Transport.sendrecv(Transport.java:63)
        - waiting to lock <0x47320060> (a java.util.HashMap)
        at jcifs.smb.SmbTransport.send(SmbTransport.java:595)
        at jcifs.smb.SmbSession.sessionSetup(SmbSession.java:264)
        - locked <0x47320088> (a jcifs.smb.SmbTransport)
        at jcifs.smb.SmbSession.send(SmbSession.java:223)
        at jcifs.smb.SmbTree.treeConnect(SmbTree.java:144)
        - locked <0x47320088> (a jcifs.smb.SmbTransport)
        at jcifs.smb.SmbFile.connect(SmbFile.java:792)
        at jcifs.smb.SmbFile.connect0(SmbFile.java:762)
        at jcifs.smb.SmbFile.open0(SmbFile.java:817)
        at jcifs.smb.SmbFile.open(SmbFile.java:846)
        at jcifs.smb.SmbFileOutputStream.write(SmbFileOutputStream.java:209)
        at com.agedwards.dniprint.CRLFOutputStream.write(CRLFOutputStream.java:53)
        at com.agedwards.dniprint.CRLFOutputStream.write(CRLFOutputStream.java:39)
        at com.agedwards.dniprint.DniDeviceWriterCifs.write(DniDeviceWriterCifs.java:237)
        at com.agedwards.dniprint.DniDeviceHandler.onMessage(DniDeviceHandler.java:518)
        - locked <0x47545610> (a com.agedwards.dniprint.DniDevice)
        at com.agedwards.dniprint.DniDeviceReaderJms$JmsListener.run(DniDeviceReaderJms.java:707)
        at java.lang.Thread.run(Thread.java:534)
"DniDeviceReaderJms-TDMS1_SAMBA27":
        at jcifs.util.transport.Transport.disconnect(Transport.java:192)
        - waiting to lock <0x47320088> (a jcifs.smb.SmbTransport)
        at jcifs.util.transport.Transport.sendrecv(Transport.java:83)
        - locked <0x47320060> (a java.util.HashMap)
        at jcifs.smb.SmbTransport.send(SmbTransport.java:595)
        at jcifs.smb.SmbSession.send(SmbSession.java:229)
        at jcifs.smb.SmbTree.send(SmbTree.java:102)
        at jcifs.smb.SmbFile.send(SmbFile.java:688)
        at jcifs.smb.SmbFile.open0(SmbFile.java:828)
        at jcifs.smb.SmbFile.open(SmbFile.java:846)
        at jcifs.smb.SmbFileOutputStream.<init>(SmbFileOutputStream.java:139)
        at jcifs.smb.SmbFileOutputStream.<init>(SmbFileOutputStream.java:97)
        at jcifs.smb.SmbFileOutputStream.<init>(SmbFileOutputStream.java:82)
        at jcifs.smb.SmbFileOutputStream.<init>(SmbFileOutputStream.java:54)
        at com.agedwards.dniprint.DniDeviceWriterCifs.write(DniDeviceWriterCifs.java:231)
        at com.agedwards.dniprint.DniDeviceHandler.onMessage(DniDeviceHandler.java:518)
        - locked <0x47545b28> (a com.agedwards.dniprint.DniDevice)
        at com.agedwards.dniprint.DniDeviceReaderJms$JmsListener.run(DniDeviceReaderJms.java:707)
        at java.lang.Thread.run(Thread.java:534)

Found 1 deadlock.

Here is the 1.2.7 Transport.sendrecv method with comments:

	public void sendrecv( Request request,
	                    Response response,
	                    long timeout ) throws IOException {
	        synchronized (response_map) {
	            makeKey( request );
	            response.isReceived = false;
	            try {
	                response_map.put( request, response );
	                doSend( request );
	                response.expiration = System.currentTimeMillis() + timeout;
	                while (!response.isReceived) {
	                    response_map.wait( timeout ); // <- thread can't resume monitor on response_map
	                    timeout = response.expiration - System.currentTimeMillis();
	                    if (timeout <= 0) {
	                        throw new TransportException( name +
	                                " timedout waiting for response to " +
	                                request );
	                    }
	                }

	            } catch( IOException ioe ) {
	                if (log.level > 2)
	                    ioe.printStackTrace( log );
	                try {
	                    disconnect( true ); //<- other thread can't get monitor on 'this' Transport
	                } catch( IOException ioe2 ) {
	                    ioe2.printStackTrace( log );
	                }
	                throw ioe;
	            } catch( InterruptedException ie ) {
	                throw new TransportException( ie );
	            } finally {
	                response_map.remove( request );
	            }
	        }
	    }

	Here is my modified Transport.sendrecv method:

	public void sendrecv( Request request,
	                    Response response,
	                    long timeout ) throws IOException {
	            try {
	              synchronized (response_map) {  
	                makeKey( request );
	                response.isReceived = false;
	                response_map.put( request, response );
	                doSend( request );
	                response.expiration = System.currentTimeMillis() + timeout;
	                while (!response.isReceived) {
	                    response_map.wait( timeout );
	                    timeout = response.expiration - System.currentTimeMillis();
	                    if (timeout <= 0) {
	                        throw new TransportException( name +
	                                " timedout waiting for response to " +
	                                request );
	                    }
	                }
	              }
	            } catch( IOException ioe ) {
	                if (log.level > 2)
	                    ioe.printStackTrace( log );
	                try {
	                    disconnect( true );
	                } catch( IOException ioe2 ) {
	                    ioe2.printStackTrace( log );
	                }
	                throw ioe;
	            } catch( InterruptedException ie ) {
	                throw new TransportException( ie );
	            } finally {
	                synchronized (response_map) {
	                   response_map.remove( request );
	                }
	            }
	       
	    }


	I allow the thread to release the monitor on the response_map while performing the disconnect and re-acquire it when the request needs to be removed from it. In my testing, I have not been able to recreate the above deadlock nor have I experienced any significant performance degradation.
	Any feedback about this approach ?

	Thanks

Tim Dalton



-------------------------------------------------------------------------------------
A.G. Edwards & Sons' outgoing and incoming e-mails are electronically
archived and subject to review and/or disclosure to someone other 
than the recipient.

-------------------------------------------------------------------------------------

-------------- next part --------------
HTML attachment scrubbed and removed