Archive for category java

ColdFusion ORM : How to log SQL

When you use ORM for developing an application, SQLs are generated and executed by the underlying ORM engine (i.e Hibernate for ColdFusion ORM). However, for both troubleshooting and performance optimization, it is crucial to monitor what queries are getting generated. It can help you find out if there is any error in mapping that you have provided as well as it can help you decide various tuning strategies.

ColdFusion can log the SQLs generated by ORM either onto the console or a file. At the same time it leaves enough hook for you to log it anywhere you want.

ColdFusion ORM provides two ways to log the SQLs.

  1. Using application setting to log to console : This is a quick and simple way to log the sql to console. This is enabled by setting “logsql” in ormsettings.

       <cfset this.ormsettings.logsql="true">

    This setting is self sufficient and it will log all the sqls executed by hibernate to the console (or a file where the server output goes). However this is not a very flexible option. The sqls are always written to the console and it will be combined with any other output that goes to console. Also this option will not show the DDL queries used for creating or updating tables. It only logs the SQL for the entity operations.

  2. Using log4J.properties: Hibernate uses log4j for its logging and you can completely control its logging (including SQL) by modifying the log4j.properties. log4j.properties is present under <cf_home>/lib directory. Please note that you don’t need to do any application specific setting for this.

 

I will go in details about using log4j.properties for SQL logging. Here is a snippet from log4j.properties file that is shipped with ColdFusion.

###--------------- Hibernate Log Settings ------ 
### Set Hibernate log 
log4j.logger.org.hibernate=ERROR, HIBERNATECONSOLE 
 
### log just the SQL 
#log4j.logger.org.hibernate.SQL=DEBUG, HIBERNATECONSOLE 
#log4j.additivity.org.hibernate.SQL=false 
### Also log the parameter binding to the prepared statements. 
#log4j.logger.org.hibernate.type=DEBUG 
### log schema export/update ### 
log4j.logger.org.hibernate.tool.hbm2ddl=DEBUG, HIBERNATECONSOLE 
### log cache activity ### 
log4j.logger.org.hibernate.cache=ERROR, HIBERNATECONSOLE 
 
# HibernateConsole is set to be a ColsoleAppender for Hibernate message  using a PatternLayout. 
log4j.appender.HIBERNATECONSOLE=org.apache.log4j.ConsoleAppender 
log4j.appender.HIBERNATECONSOLE.layout=org.apache.log4j.PatternLayout 
log4j.appender.HIBERNATECONSOLE.layout.ConversionPattern=%d{MM/dd HH:mm:ss} [%t] HIBERNATE %-5p - %m%n%n 
#---------------------------------------------

First we will see the relevant settings for SQL logging:

  • log4j.logger.org.hibernate.SQL : Defines whether the SQL executed for entity operations will be logged and where it will be logged. The second value for this i.e ‘HIBERNATECONSOLE’ is a appender that controls where the SQLs will be logged. In the above example HIBERNATECONSOLE is a ‘console’ appender which means it will log the sql to console.
  • log4j.logger.org.hibernate.type : Defines whether parameter values used for parametrized query will be logged.
  • log4j.logger.org.hibernate.tool.hbm2ddl : Defines whether DDL sql statements will be logged.

To enable the SQL logging for console, we just need to uncomment the settings mentioned above. Here is how the hibernate log settings in log4j.properties file would look like

###--------------- Hibernate Log Settings ------ 
### Set Hibernate log 
log4j.logger.org.hibernate=ERROR, HIBERNATECONSOLE 
 
### log just the SQL 
log4j.logger.org.hibernate.SQL=DEBUG, HIBERNATECONSOLE 
log4j.additivity.org.hibernate.SQL=false 
### Also log the parameter binding to the prepared statements. 
#log4j.logger.org.hibernate.type=DEBUG 
### log schema export/update ### 
log4j.logger.org.hibernate.tool.hbm2ddl=DEBUG, HIBERNATECONSOLE 
### log cache activity ### 
log4j.logger.org.hibernate.cache=ERROR, HIBERNATECONSOLE 
 
# HibernateConsole is set to be a ColsoleAppender for Hibernate message  using a PatternLayout. 
log4j.appender.HIBERNATECONSOLE=org.apache.log4j.ConsoleAppender 
log4j.appender.HIBERNATECONSOLE.layout=org.apache.log4j.PatternLayout 
log4j.appender.HIBERNATECONSOLE.layout.ConversionPattern=%d{MM/dd HH:mm:ss} [%t] HIBERNATE %-5p - %m%n%n 
#---------------------------------------------

Here is the complete log4j.properties for logging SQL for console. Ofcourse after changing this you need to restart the server. If you need to log the parameter values used for queries, you need to uncomment ‘#log4j.logger.org.hibernate.type=DEBUG’ as well.

What if you want to log the SQL to a file and not to console? That is pretty easy. You just need to change the ‘Appender’ used here (HIBERNATECONSOLE) to point to a ‘FileAppender’ instead of a ConsoleAppender. Here is how the configuration for HIBERNATECONSOLE should look like after you point it to a File Appender.

log4j.appender.HIBERNATECONSOLE=org.apache.log4j.FileAppender
log4j.appender.HIBERNATECONSOLE.File=../hibernatesql.log
log4j.appender.HIBERNATECONSOLE.Append=true
log4j.appender.HIBERNATECONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.HIBERNATECONSOLE.layout.ConversionPattern=%d{MM/dd HH:mm:ss} [%t] HIBERNATE %-5p - %m%n%n

For standalone ColdFusion installation, the file ‘hibernatesql.log’ will be created in the /logs directory.You can also specify a full path of the file for property ‘log4j.appender.HIBERNATECONSOLE.File’ and the log will be written to that.

That was easy. Isn’t it? What if you want a rolling log file where you dont want the log file size to grow infinitely. That is fairly easy too. All you need to do is to use an appropriate appender. The appender definition for that will look like

log4j.appender.HIBERNATECONSOLE=org.apache.log4j.RollingFileAppender
log4j.appender.HIBERNATECONSOLE.File=../hibernatesql.log
log4j.appender.HIBERNATECONSOLE.Append=true
log4j.appender.HIBERNATECONSOLE.MaxFileSize=500KB
log4j.appender.HIBERNATECONSOLE.MaxBackupIndex=3
log4j.appender.HIBERNATECONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.HIBERNATECONSOLE.layout.ConversionPattern=%d{MM/dd HH:mm:ss} [%t] HIBERNATE %-5p - %m%n%n

Here is the complete log4j.properties for logging SQL to a file that will be rolled automatically once it reaches 500KB.

Now that you have seen how easy it is to change one ‘Appender’ to another, you can pretty much log it anywhich way you want. Here are some of the interesting ‘Appender’s that come with log4j which you can easily use.

DailyRollingFileAppender, ExternallyRolledFileAppender, JMSAppender, SMTPAppender, SocketAppender, SyslogAppender

See log4J for more details on log4j settings.

Tags: , , ,

DNS lookup Caching in ColdFusion/Java

Two days back, I got an interesting question from our support team. The Customer in this case was using CFLdap which connected to a particular LDAP server and things were working fine. The problem came when they replaced this LDAP server with another LDAP server and assigned the same dns name to the new ldap server. Ideally any connection made henceforth should have worked with the new ldap server but actually that did not happen. ColdFusion started throwing error and it did not work until the ColdFusion server is restarted. Ever seen something similar?

It is obvious that it happend because the IP address was being cached for the host name as a result of which ColdFusion was still trying to connect to the old IP address even though the host name now pointed to a different IP address. This caching also applies for all other network protocol tags such as CFHTTP, CFFTP, CFFEED etc and is not limited to CFLDAP. It is actually the JVM that does this caching. When JVM is requested to resolve a host name, it does the host name to IP address resolution and caches the result. This result will be used for all subsequent lookups. It also caches the negative results. By that I mean, if the dns reolution fails, it caches the failed result for a certain period so that any lookup for that hostname in that period will not result into another resolution on network and will immediately return the failed result.

For more detail on this caching, check out the Javadoc for InetAddress class.

As per this doc, there are two parameters that control this caching

networkaddress.cache.ttl (default: -1) : Indicates the caching policy for successful name lookups from the name service. The value is specified as as integer to indicate the number of seconds to cache the successful lookup.A value of -1 indicates “cache forever”.

networkaddress.cache.negative.ttl (default: 10) : Indicates the caching policy for un-successful name lookups from the name service. The value is specified as as integer to indicate the number of seconds to cache the failure for un-successful lookups.A value of 0 indicates “never cache”. A value of -1 indicates “cache forever”.

Now where do you specify this settying? You can specify this setting in <Java_home>/jre/lib/security/java.security file. For standalone ColdFusion server it will be in <ColdFusion _dir>/runtime/jre/lib/security/java.security file.

As you see, by default networkaddress.cache.ttl caches the result for ever and hence it is configured for best performance. Any change to this mean drop in performance. If you don’t want to cache the resolved IP address for ever, as is the case here, you would need to change networkaddress.cache.ttl value to 60 seconds or 300 seconds or any value you feel suitable. You would not want to set it to 0 as that would mean “never cache” the result which might affect the performance significantly.

In which case you would want to change the value for networkaddress.cache.negative.ttl? That would be mostly in case when you want to cache the negative result for a longer time and in turn improving the performance. For example, if you are trying to connect to a hostname which can not be resolved to any ip address, and that happens very frequently, each of the call (as long as they are not in the same 10 sec window) would become very slow. Increasing this value would increase the performance but again you would not want to cache the negative result for ever.

After you change this setting, you will have to restart the ColdFusion server for this change to take effect.

Tags: , ,

ColdFusion and WebService : “class file has wrong version”

I can’t even count the number of times I have seen this error while QA folks were running webservices regressions for ColdFusion 8. Everytime, someone was running webservices tests on a J2EE configuration they used to get an error :

coldfusion.jsp.CompilationFailedException: Errors reported by Java compiler:
….
class file has wrong version 49.0, should be 48.0

I saw the same error posted in the public forum where the user had deployed ColdFusion 8 on JRun with JDK1.5 and was trying to invoke webservice. And hence this blog entry :-)

This error comes because of incompatibility between the tools.jar and the JVM version. ColdFusion 8 ships Java 1.6′s tools.jar (you will find it in cfusion/lib) which is of course incompatible with any other JDK/JRE version. You will see the same behavior with ColdFusion 7 as well, if you run it on a JVM other than 1.4. So the rule of thumb is – if ColdFusion is running on a JVM version other than the shipped one, you must ensure that the tools.jar is in synch. In short, you will need to copy JDK’s tools.jar to cfusion/lib.

Tags: ,

Using CFFeed with URL sending compressed content

Today someone posted on ColdFusion forum regarding this problem where cffeed was not able to handle a particular URL and it was throwing an error. The URL which he tried was http://movies.msn.com/rss/topcelebs and it failed with an error

Unable to read the source URL.
unknown compression method

The reason it happens is – The URL returns the response in gzip compressed format only. So when ColdFusion sent a request to this URL and asked for uncompressed data, it could not get anything and hence it was unable to read it. A simpe workaround for this is to use cfhttp to fetch the content, write to a temporary file and then use the cffeed tag to read this file. Important thing to keep in mind here is to set an additional header in the cfhttp tag using cfhttpparam to indicate that it can accept compressed data as well.

Here is the modified code where it first tries cffeed with the URL. If that fails, then it tries to use cfhttp to fetch the content and writes to a temporary file and then uses it in cffeed.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
<cfset tempDir=GetTempDirectory()>
<cfset tempFile = GetTempFile(tempDir, "myfeed")>
<cfset tempFileName = GetFileInfo(tempFile).name>
 
<cftry>
    <cffeed action="read" source="http://movies.msn.com/rss/topcelebs" name="feedInStruct" >
<cfcatch any>
    <cfhttp url="http://movies.msn.com/rss/topcelebs" path="#tempDir#" file="#tempFileName#">
        <cfhttpparam type="header" name="Accept-Encoding" value="compress,gzip,deflate">
    </cfhttp>
    <cffeed action="read" source="#tempFile#" name="feedInStruct" >
</cfcatch>
</cftry>
<cfif FileExists(tempFile)>
    <cfset FileDelete(tempFile)>
</cfif>
 
<cfdump var="#feedInStruct#">

Tags: ,

Finding Image Type for a file

This is a follow up on my previous post on URLConnection APIs
We will use this API to find out the image type of a given file. Here is the udf.

&lt;cffunction name="getMimeType"&gt;
    &lt;cfargument name="filepath"&gt;
 
    &lt;cfset var urlConn = createObject("java", "java.net.URLConnection")&gt;
    &lt;cfset var fileobj = fileopen(filepath, "readbinary")&gt;
    &lt;!--- just read the first 20 characters of the file as thats sufficient ---&gt;
    &lt;cfset var bytes = fileread(fileobj, 20)&gt;
    &lt;cfset var istream = createObject("java", "java.io.ByteArrayInputStream").init(bytes)&gt;
    &lt;cfset fileobj.close()&gt;
    &lt;cfreturn urlConn.guessContentTypeFromStream(istream)&gt;
&lt;/cffunction&gt;
&lt;cffunction name="GetImageType"&gt;
    &lt;cfargument name="filepath"&gt;
    &lt;cfset var mimetype = getMimeType(filepath)&gt;
    &lt;cfset var imagetype=""&gt;
    &lt;cfif not isDefined("mimetype")&gt;
        &lt;cfthrow message="Not an Image file"&gt;
    &lt;/cfif&gt;
    &lt;cfswitch expression="#mimetype#"&gt;
        &lt;cfcase Value="image/gif"&gt;
            &lt;cfset imagetype="gif"&gt;
        &lt;/cfcase&gt;
        &lt;cfcase Value="image/x-bitmap"&gt;
            &lt;cfset imagetype="bmp"&gt;
        &lt;/cfcase&gt;
        &lt;cfcase Value="image/png"&gt;
            &lt;cfset imagetype="png"&gt;
        &lt;/cfcase&gt;
        &lt;cfcase Value="image/jpeg"&gt;
            &lt;cfset imagetype="jpeg"&gt;
        &lt;/cfcase&gt;
        &lt;cfcase Value="image/jpg"&gt;
            &lt;cfset imagetype="jpeg"&gt;
        &lt;/cfcase&gt;
        &lt;cfdefaultcase&gt;&lt;cfthrow message="Not an Image file"&gt;
        &lt;/cfdefaultcase&gt;
        &lt;/cfswitch&gt;
        &lt;cfreturn imagetype&gt;
&lt;/cffunction&gt;

If I run the code below

&lt;cfset filepath = "C:\temp\test.jpg"&gt;
&lt;cfoutput&gt;#GetImageType(filepath)#&lt;/cfoutput&gt;

It nicely prints out “jpeg”.

You should note that I used the new File IO function added in ColdFusion 8 using which I can read as many no of bytes from the file as I want. No more reading the entire file into memory.

More extensive post on File IO functions coming next !

Finding mime type of any file

Hemant recently told me about this cool API in java.net.URLConnection which can tell you the mime type for common file types.

guessContentTypeFromName(String name) – that simply checks the extension of the file name specified and gets the mime type from a static map it maintains. This can be very useful in many scenarios. The map it uses is quite extensive and contains almost all the mime types.

But this has a problem. What if some one has renamed a gif to jpg? This method will say that the file is a jpg image whereas it was a gif.

Thankfully there is another method in the same class which can address this problem.

guessContentTypeFromStream(InputStream stream) – which reads the stream, takes a look at the initial bits of the file and uses that to determine the file type.
This method does a check for the following mime types :-


- application/java-vm
- application/x-java-serialized-object
- text/html
- application/xml
- image/gif
- image/x-bitmap
- image/x-pixmap
- image/png
- image/jpeg
- image/jpg
- image/vnd.fpx
- audio/basic
- audio/x-wav

Though this method leaves out many of other common types such as mp3, it is still very useful. This makes it so easy to find out the type of an image.

Use Java 5 feature in Jdk1.4

I have been getting the itch for a long tome to use Java 5 features like generics, new concurrency (java.util.concurrent), autoboxing, “for each” loop and many more. But sadly I can not do it at work because ColdFusion has to be supported on all application servers. Since many of the application servers are still on J2EE 1.4 and not all of them are compatible with Java 5, we have to write JDK1.4 compliant code. Which means that all those wonderful features of Java5 can not be used for some more time to come. Or so I thought until yesterday when I read Brian Goetz’s (of “Java concurrency in practice” fame) article which says that we can use some of the Java features in JDK1.4 also.
At first I was kind of puzzled as in how could that be possible? Did they had these features and they just did not mention about it in JDK1.4 or probably they just sneaked it in 1.4 in last moment but not talk about it because of some reasons.

It dawned to me when I went halfway through the article. It looks like most of these new syntaxes did not need any change in the bytecode instruction set which means that the compiler would generate the same bytecodes or instruction set for it as it would have for equivalent code without using these features. So it should be possible to use a class created by java5 compiler in 1.4. But don’t we get UnsupportedClassVersionError when we try to do that?

Here is the catch. Due to some reasons they had to change the class version and that is why this UnsupportedClassVersionError. However these guys added a flag to java compiler (which ofcourse is undocumented) that can allow this. You need to invoke javac with “-source 1.5 -target jsr14″ option and this will generate 1.4 compatible bytecodes for java5 syntax. This means I can happily write my code using generics, autoboxing, for..each loop, compile it with java5 compiler with this flag and be assured that this can run on 1.4 VM also.

That leaves one more set of features i.e; new concurreny, which I really really like in java5 and want to use. Thankfully some guys at Distibuted Computing Lab at Emory University have backported java5 concurrency (java.uti.concurrent) features that can be used in java 1.3+. I have infact used it and it is awesome !

So most of the juicy stuffs that were added in java5 can run on 1.4. Off to checking it out little more. :)

java.net article on ColdFusion and JavaEE

I found this interesting article by Kola Oyedeji on java.net. He talks about integration between ColdFusion and JavaEE and how this could be of interest to JSP developers.
We in our team here have discussed it so many times that why can not ColdFusion be used by J2EE/JSP developers or enterprises that standardize on J2EE. ColdFusion is a pure J2EE solution, runs on all the major applications servers, is so feature rich, so productive that it should be a no brainer for everyone to adapt this. And to this when I add the features that we are adding in Scorpio, it makes even more sense. I don’t think there is any other platform which can come even close to CF in terms of features and productivity.
At MAX, I had a conversation with one of our customers and he said something very interesting. His client wanted a pure J2EE solution and his competitors were asking for nearly 6 months to implement this. So this guy did everything in CF, bundled it as an ear (that can be deployed on application server) and shipped in flat one month !! And his client never ever thought that this was a CF application. :D

Good to see this kind of article on a java website.

Accessing password protected URL

How do you access a password protected URL (requiring basic authentication) programmatically? well, there are two ways

  1. If you know that the URL is protected : This is the simple one. Since you know the URL is protected, add the required authorization header in the request and you are done. What if you are not making the socket connection but instead using java.net.URL or java.net.URLConnection to retrieve the content of url? You can use setRequestProperty() method of URLConnection to add any request header you want. So the code would look like
    URL url = new URL(someurlstring);
    URLConnection conn = url.openConnection();
    String encoding = new sun.misc.BASE64Encoder().encode("username:password".getBytes());
    conn.setRequestProperty ("Authorization", "Basic " + encoding);
    InputStream in = conn.getInputStream()
    ...
  2. What if you dont know in advance whether the URL is protected or not? You can not arbitrarily add the authorization heder for all the URLs. The answer to this is “java.net.Authenticator”. You need to install an instance of java.net.Authenticator using setDefault() method of Authenticator. Whenever URLConnection sees that the url is protected, it will use this installed authenticator to get the username and password and set the required authorization header automatically.
    Here is how the code snippet for doing this

    Authenticator.setDefault(new MyAuthenticator());
    ....
     
    public class MyAuthenticator extends Authenticator
    {
     protected PasswordAuthentication getPasswordAuthentication()
     {
         return new PasswordAuthentication ("username", "password");
     }
    }

    This particular technique is particularly useful for people who need a workaround for retrieving password protected images in cfdocument. Here is what you need to do.

    • Use the source below to create Authenicator class
      import java.net.*;
      public class MyAuthenticator extends Authenticator
      {
          private String user;
          private String passwd;
       
          public MyAuthenticator(String user, String passwd)
          {
              this.user = user;
              this.passwd = passwd;
          }
       
          protected PasswordAuthentication getPasswordAuthentication()
          {
              return new PasswordAuthentication(user, passwd.toCharArray());
          }
      }

      Compile this and put MyAuthenticator.class in wwwroot/WEB-INF/classes.

    • Put the following code in your application.cfm or application.cfc
      <cfif not IsDefined("Application.authenticator")>
            <!--- Do initializations --->
            <cfset authenticator= createObject("java", "java.net.Authenticator")>
            <cfset myauthenticator = createObject("java", "MyAuthenticator").init("username", "password")>
            <cfset authenticator.setDefault(myauthenticator)>
            <cfset Application.authenticator=myauthenticator>
      </cfif>

      replace “username” and “password” with actual username and password.

    • give the request for the cfdocument page for which you were getting the red-x for image. The images should appear this time.

The Mystery of "Too many open files"

Last week we saw an interesting problem while running the regression tests on Linux. Immediately after the tests were started, the VM started throwing error “FileNotFoundException : Too many open files”. Ofcourse the files were there but the VM was trying to say that there are too many file descriptors open which were not closed. It was hitting the open file limit set by the OS. This was kind of absurd because we always close all the files that we open. And moreover we had never seen this problem before. So we started suspecting 1.6 VM on which we were running it.

Immediately after this, it got worse. The exception changed into “SocketException: Too many open files” and all the socket connection started getting rejected. So merely after serving 100 requests, the server was down to its knees.

A quick google search suggested to increase the open file descriptor limit on the machine.

“ulimit -aH” that gives the max limit for number of open files returned 1024.

I added every possible way to increase it. Here are few

1. In /etc/security/limits.conf
* soft nofile 1024
* hard nofile 65535
2. Increase ulimit by “ulimit -n 65535″
3. echo 65535 > /proc/sys/fs/file-max
4. In /etc/sysctl.conf
fs.file-max=65535

Increasing file descriptor limit did not help much either. Even after increasing this limit, we were still getting this error.And then Sanjeev (another brilliant CF engineer with an amazing sense of humour) cracked it !!
Just before we started getting these errors, there was another error which I had overlooked assuming it was test problem which infact was the clue.
The error was something like
coldfusion.jsp.CompilationFailedException: Errors reported by Java compiler: error: error reading /opt/coldfusionscorpio/lib/./././././././././././././././././././././././././././././
././././././././././././././././././././././././././././././././././././././././././.
/././././././././././././././././././././././././././././././././././././././././././
././././././././././././././././././././././././././././././././././././././././././.
/././././././././././././././././././././././././././././././././././././././././././
././././././././././././././././././././././././././././././././././././././././././.
/././././././././././././././././././././././././././././././././././././././././././
././././././././././././././././././././././././././././././././././././././././././.
/././././././././././././././././././././././././././././././././././././././././././
././././././././././././././././././././././././././././././././././././././././././.
/././././././././././././././././././././././././././././././././././././././././././
././././././././././././././././././././././././././././././././././….
at coldfusion.jsp.JavaCompiler.compileClass(JavaCompiler.java:138)

Sanjeev ran it through the debugger and he nailed the culprit. It was something which no one had even suspected. It was javac. :)
We had hit upon a Sun’s bug in javac where if the classpath contains a jar which has a manifest and manifest contains classpath entry with relative paths of other jars as well as path to itself, javac goes in an infinite loop. (Sun’s bug no 6400872, 6446657, 6456960, 6485027, 6206485)

I dont have the source for javac to pin point what exactly it did, but probably it kept opening all the entries in the classpath and because of the stack overflow it could not close those files – hence reaching the max limit of open file descriptors. This was a third party jar that had this manifest entry. Once we found the problem, the solution was simple – just remove the classpath entry from the manifest! Whew !!!