Guest?
 
Project
SVNKit
Priority
Normal
Type
Bug
State
Submitted
Assignee
Alexander Kitaev
Subsystem
Working Copy
Affected versions
1.3.5
Fix versions
No Fix versions
Fixed in build
No Fixed in build
  • Created by   Tomasz Geisel
    13 months ago (10 May 2012 19:40)
  • Updated by   Tomasz Geisel
    12 months ago (30 May 2012 17:15)
0
Issue is visible to: All Users
  The issue is visible to the selected user group only
Hi Guys,

We're running the standalone svnkit + jna on Solaris:
SunOS unknown 5.10 Generic_142910-17 i86pc i386 i86pc

Our application is constantly failing on commit attempt with 'permission denied'

svn: Cannot read from 'somefile': somefile (Permission denied)

We tried the code on different platforms without any issues (Windows/Linux).
We are pretty sure that file system permissions are setup correctly and it's not the problem - the exact same issue appears for every client that is running on Solaris.

You'll find the svnkit logs with full stacktrace in attachment.
Please take a look.

Thank you in advance!
Comments (14)
 
History
 
Linked Issues (?)
 
TeamCity Changes (0)
 
Dmitry Pavlenko
  Dmitry Pavlenko
11 May 2012 13:28
13 months ago
Hello. Does this particular case cause problems or doesn't "jsvn commit" work at all for your system?
Tomasz Geisel
  Tomasz Geisel
14 May 2012 12:14
13 months ago
Hi Dmitry,

Commit is failing for almost all operations. Due to this it's not possible for us to use svnkit on Solaris.
Attached is the svnkit log from today.
Related Attachments
Alexander Kitaev
  Alexander Kitaev
14 May 2012 16:13
13 months ago
Hello Tomasz,

Thank you for the log file. May I ask you a few more questions regarding this issue:

1. Is this issue only reproducible with JNA library on classpath? On the email your colleague reported that this issue is JNA-related, is that correct?
2. What version of JDK do you use?
3. What version of SVNKit do you use? Did you try newest 1.7.4-v1 version with the new working copy format?

We have installed Solaris OS on a virtual machine and so far did not manage to reproduce the problem both with SVNKit 1.3.5 and newer 1.3.7 version.

Regarding the exception itself (permission denied) - one of the possible reasons for that exception (besides actual permissions problem) is that there is another process running which reads, writes or deletes temporary file at the same time when commit operation is running. Among such processes there are usually antivirus software or indexing programs that tracks and watches files being created or modified. So, if possible, please check if there are such background process running on your Solaris box and disable it to check if it may be the reason of the problem.

Thanks!
Tomasz Geisel
  Tomasz Geisel
15 May 2012 11:00
13 months ago
Hi Alexander,

1. Yes, the issue is reproducible only with JNA on the classpath. If we remove JNA all tests complete successfully but performance is significantly degraded.
2. JDK is in version: Sun 1.6.0_24 (50.0), VM: Java HotSpot(TM) 64-Bit Server VM, build: 19.1-b02, mixed mode
3. We tried newest 1.7.4-v1 with JNA in classpath and it looks that access denied problem is gone - version prior 1.7.4-v1 were braking for us due to issue.
With 1.7.4-v1 + JNA performance is really weak (average the same as 1.3.5 w/o JNA) so it seems that JNA is not used. Is there a way I can verify that SVNKIT is actually using JNA?

It's good news that with 1.7.4-v1 the issue is resolved however the same performance score as 1.3.5 w/o JNA makes us believe JNA is not used at all (it is in classpath). Could you please help us troubleshooting this?

When running 1.7.4-v1 with JNA we don't see any library related to jnidispatch in temporary dir. For 1.3.5 with JNA - jnidispatch lib is properly created in temp dir and loaded from there.

Verified background processes - there are no other processes that access svnkit temporary files.
Thanks for your help!
Alexander Kitaev
  Alexander Kitaev
15 May 2012 18:02
13 months ago
Hello Tomasz,

SVNKit 1.7.4-v1 uses newer version of JNA (JNA 3.4.0). I've just tested it on Windows and JNA is used by SVNKit. Unfortunately there is no information written to log in that version on whether JNA is actually used, but you may calls SVNJNAUtil.isJNAPresent/Enabled methods at runtime to check whether JNA is present and used.

We will check if JNA is used by 1.7.4-v1 on our VM Solaris.

With JDK 1.6 there is no way to improve performance without JNA been used. However, if you could switch to 1.7 then you may expect better performance without JNA as soon as we add JDK new IO API support to SVNKit, which we expect to do in a few weeks.

Thanks! I'll keep you updated on the status of our investigations.
Alexander Kitaev
  Alexander Kitaev
18 May 2012 23:58
13 months ago
I've performed more test with SVNKit 1.7.4-v1 on Solaris in VirtualBox:

Solaris version (64 bit):
SunOS unknown 5.10 Generic_147441-01 i86pc i386 i86pc

Java version:
Java(TM) SE Runtime Environment (build 1.6.0_26-b03)
Java HotSpot (TM) Client VM (build 20.1-b02, mixed mode, sharing)

SVNKit 1.7.4-v1 (with additional logging)

With the above configuration I can confirm that JNA (version 3.4.0) is loaded and used, commit works fine both with the old and new working copy formats.

If possible, please try this build of SVNKit in your environment with logging enabled: http://teamcity.tmatesoft.com/viewLog.html?buildId=2703&tab=artifacts&buildTypeId=bt43

To enable debug logging add the following Java VM argument:

  • Djava.util.logging.config.file=logging.properties

where logging.properties is:

svnkit.level=FINEST
svnkit-network.level=FINEST
svnkit-wc.level=FINEST
svnkit-cli.level=FINEST
handlers = java.util.logging.FileHandler

java.util.logging.FileHandler.pattern = svnkit.%u.log
java.util.logging.FileHandler.limit = 0
java.util.logging.FileHandler.count = 1
java.util.logging.FileHandler.append = true
java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter


Try using that build and then please send me the log file (or attach it to this issue). This log will contain more information on JNA usage.

To disable new working copy format support (so, that working copies are created in the old format, same as used by SVNKit 1.3.7), you may use the following command line argument:

  • Dsvnkit.wc.17=false

Thanks a lot in advance for your help!
Tomasz Geisel
  Tomasz Geisel
21 May 2012 22:38
12 months ago
Hi Alexander,

Thank you for the details and new build.
I did the test with provided svnkit snapthot and here are the logs attached - svnkit_logs_for_SNAPSHOT_r9229_v20120518_2250.zip.

With this version I'm getting exceptions the NETWORK: svn: E210004: Malformed network data. Error is persistent with 1.7.4-v2 - I repeated the test with 1.7.4-v1 to verify if it's something introduced with 1.7.4-v2 - with old version test completed successfully.

Please take a look - thanks in advance!
Alexander Kitaev
  Alexander Kitaev
22 May 2012 18:20
12 months ago
Hello Tomasz,

Thank you very much for the log file!

First, regarding "malformed data" error: accordingly to the log it is caused by "Connection Reset" exception, which means that TCP/IP connection is closed on the server side. One of the reasons might be server-side socket write timeout (when it takes too long for the client to process data being received), other reasons are mostly related to the firewall/iptables configuration. You report that 1.7.4-v1 does not suffer from that issue, are you confident about it? May it be that 1.7.4-v1 also fails occasionally with the same error? At least so far I can't see any changes between v1 and v2 that might affect network related code in SVNKit. I will continue to look for.

Second, from the log it could be understood that SVNKit does not use JNA properly in your environment. It loads it, uses but finally receives wrong results and runs pure Java substitution code to get proper file type for instance. This slow downs the execution, plus it may theoretically result in other issues (like originally reported "permission denied" one).

The reason of that problem is that SVNKit JNA-related code for Solaris is only valid for 32-bit system and you run Java in 64-bit mode. On my VM Solaris I could not reproduce JNA-issues when run "jsvn" script (that invokes "java ...") but I did manage to reproduce output similar to those you have in log when add "-d64" to the java command line arguments. Do you pass this argument (-d64 or -server) to "java" program? Could you please try removing it to see if it resolves JNA-related problems?

Meanwhile we will try to add code that handles 64-bit environment on Solaris properly.

Thanks!
Alexander Kitaev
  Alexander Kitaev
23 May 2012 14:37
12 months ago
I'd like to add that in order to enforce JVM to run in 32-bit mode you may add "-d32" option when starting java, in case default mode is 64-bit.
guest
  guest
23 May 2012 19:23
12 months ago
Hi Alexander,

I tried your recommendation and set "-d32" switch and verified that JVM was indeed in Java Data Mode 32-bit.
This time there was no 'malformed data' so it really could be transient issue.
Test completed successfully without issues but with poor performance so it seems JNA is still not used.

Please find the log attached: svnkit_logs_v2_20120523 (it's split with zip into two archives since exceeded the upload limit for one file)
Let me know if you would need any other details.

Many thanks for help!
Alexander Kitaev
  Alexander Kitaev
24 May 2012 19:12
12 months ago
Thank you Tomasz,

Unfortunately I can't open logs (I've concatenated these two files, but zip program says it is not a valid archive). Could you please run a smaller checkout (like check out a few folders) - this would be enough to see if JNA is used and log will be much shorter.

Another thing to check is whether "-d32" indeed makes JVM run in 32-bit mode. In documentation it is said, that on pure 64-bit Solaris systems, only 64-bit mode is available and 32-bit is ignored. To check this, run "java -d32 version" and "java -version" (or "java -d64 -version") commands. You'll see whether or not 64-bit JVM is used, it should not be used in the first case.

In case -d32 option is ignored and JVM is always ran in 64-bit mode, then you'll have to wait until we add support for 64-bit Solaris to SVNKit JNA-related code. I expect it to be added in a week or so.
Tomasz Geisel
  Tomasz Geisel
25 May 2012 13:11
12 months ago
Hello Alex,

Thanks for your suggestions.
I tried the simple commit (logs are small) for both cases -d32 and -d64. Please find attached to the ticket.
I'm including also the screenshot with details for check with 'java -dXX -version'.

Many thanks.
Related Attachments
Alexander Kitaev
  Alexander Kitaev
25 May 2012 18:38
12 months ago
Hello Tomasz,

Thank you for the logs. Now your logs are similar to those I'm getting in Virtual Box. JNA was not used properly in 64-bit mode, but it was used properly in 32-bit mode. In case you experience performance issues in 32-bit mode too, then they might be not related to the JNA (or JNA calls themselves might be slow on Solaris in 32 bit mode).

Meanwhile, I've fixed SVNKit JNA code to work properly on 64-bit Solaris, both in trunk and in 1.3.x branch. Fix in 1.3.x is included into 1.3.8 bugfix release that will be published today, and trunk fix will be part of SVNKit 1.7.5 that will be released next week.
Tomasz Geisel
  Tomasz Geisel
30 May 2012 17:15
12 months ago
Hi Alexander,

Thank you for the update.
I tried the 1.3.8 release in 64-bit mode - looks the JNA library is loaded now and tests passed successfully.
To see dynamic libraries loaded by JVM I used Solaris' 'pldd' - with it I can see that for JVM process there is linked file:
/var/tmp/sag1/jna/jna7148067692653155490.tmp

But when I check on the disk there is no such file (JVM and SVNKit still running at this time).
Shouldn't the file be there? Is it expected?
With SVNKit 1.3.5 file was created in temp dir and present as long as JVM/SVNKit was loaded.

I'm asking because the measured performance is still the same with or without JNA in classpath.
But as you said it may be related to performance on virtual machine or specific bit mode.

I will let you know how the tests goes on the client end.
Thanks!
Apply Command

Command Preview: