0

Apologies if this question has been asked before, I have gone through similar posts on SO and none of the solutions have worked for me so far. The hibernate select is throwing a com.sybase.jdbc4.jdbc.SybSQLException: Implicit conversion from datatype 'VARCHAR' to 'INT' is not allowed. Use the CONVERT function to run this query. and I wanted to see whats happening with the select query.

These are the versions that I am using in my project:

<spring.version>5.2.0.RELEASE</spring.version>
<spring-boot.version>2.2.0.RELEASE</spring-boot.version>
<spring-boot-dev-tools.version>2.2.6.RELEASE</spring-boot-dev-tools.version>
<hibernate.version>5.4.6.Final</hibernate.version>
<spring-data.version>2.2.0.RELEASE</spring-data.version>

This is what my hibernate properties (for the same of brevity, not showing the entire set of hibernate properties here)

#Hibernate Properties
hibernate.show_sql=true
hibernate.use_sql_comments=true
hibernate.format_sql=true
hibernate.type=trace
hibernate.dialect=org.hibernate.dialect.SybaseASE15Dialect

I also have in my property file:

spring.jpa.show-sql=true
spring.jpa.properties.hibernate.format_sql=true

And my log4j.xml has these:

    <logger name="org.hibernate">
        <level value="TRACE"/>
    </logger>
    <logger name="org.hibernate.sql">
        <level value="TRACE"/>
    </logger>
    <logger name="org.hibernate.type">
        <level value="TRACE"/>
    </logger>

Even after setting up these many configs, I still don't see the exact select query with values in it. I also have a feeling that the logging level isn't actually working because I don't see any excessive logging from hibernate. Also, I have done the maven build multiple time just to make sure that the new properties are built. This is how the log looks like:

INFO  2020-06-08 11:35:41.392 [main] org.springframework.data.repository.config.RepositoryConfigurationDelegate  - Bootstrapping Spring Data repositories in DEFAULT mode.
INFO  2020-06-08 11:35:41.477 [main] org.springframework.data.repository.config.RepositoryConfigurationDelegate  - Finished Spring Data repository scanning in 60ms. Found 0 repository interfaces.
INFO  2020-06-08 11:35:41.482 [main] org.springframework.data.repository.config.RepositoryConfigurationDelegate  - Bootstrapping Spring Data repositories in DEFAULT mode.
INFO  2020-06-08 11:35:41.655 [main] org.springframework.data.repository.config.RepositoryConfigurationDelegate  - Finished Spring Data repository scanning in 172ms. Found 2 repository interfaces.
INFO  2020-06-08 11:35:45.855 [MLog-Init-Reporter] com.mchange.v2.log.MLog  - MLog clients using slf4j logging.
INFO  2020-06-08 11:35:46.099 [main] com.mchange.v2.c3p0.C3P0Registry  - Initializing c3p0-0.9.5.2 [built 08-December-2015 22:06:04 -0800; debug? true; trace: 10]
INFO  2020-06-08 11:35:48.331 [main] org.hibernate.Version  - HHH000412: Hibernate Core {5.4.6.Final}
INFO  2020-06-08 11:35:48.622 [main] org.hibernate.annotations.common.Version  - HCANN000001: Hibernate Commons Annotations {5.1.0.Final}
INFO  2020-06-08 11:35:53.250 [main] org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean  - Initialized JPA EntityManagerFactory for persistence unit 'MyServer'
INFO  2020-06-08 11:35:54.075 [main] com.datastax.driver.core  - DataStax Java driver 3.7.1 for Apache Cassandra
INFO  2020-06-08 11:35:54.119 [main] com.datastax.driver.core.GuavaCompatibility  - Detected Guava >= 19 in the classpath, using modern compatibility layer
INFO  2020-06-08 11:35:55.011 [main] com.datastax.driver.core.Native  - Could not load JNR C Library, native system calls through this library will not be available (set this logger level to DEBUG to see the full stack trace).
INFO  2020-06-08 11:35:55.012 [main] com.datastax.driver.core.ClockFactory  - Using java.lang.System clock to generate timestamps.
INFO  2020-06-08 11:35:55.847 [main] org.quartz.impl.StdSchedulerFactory  - Using default implementation for ThreadExecutor
INFO  2020-06-08 11:35:55.936 [main] org.quartz.core.SchedulerSignalerImpl  - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
INFO  2020-06-08 11:35:55.940 [main] org.quartz.core.QuartzScheduler  - Quartz Scheduler v.2.1.7 created.
INFO  2020-06-08 11:35:55.944 [main] org.quartz.simpl.RAMJobStore  - RAMJobStore initialized.
INFO  2020-06-08 11:35:55.948 [main] org.quartz.core.QuartzScheduler  - Scheduler meta-data: Quartz Scheduler (v2.1.7) 'quartzScheduler' with instanceId 'NON_CLUSTERED'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

INFO  2020-06-08 11:35:55.948 [main] org.quartz.impl.StdSchedulerFactory  - Quartz scheduler 'quartzScheduler' initialized from an externally provided properties instance.
INFO  2020-06-08 11:35:55.948 [main] org.quartz.impl.StdSchedulerFactory  - Quartz scheduler version: 2.1.7
INFO  2020-06-08 11:35:55.948 [main] org.quartz.core.QuartzScheduler  - JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@136690b1
INFO  2020-06-08 11:35:56.029 [main] org.springframework.scheduling.quartz.SchedulerFactoryBean  - Starting Quartz Scheduler now
INFO  2020-06-08 11:35:56.029 [main] org.quartz.core.QuartzScheduler  - Scheduler quartzScheduler_$_NON_CLUSTERED started.
INFO  2020-06-08 11:35:56.038 [main] com.abcde.MyServer  - Started MyServer in 16.772 seconds (JVM running for 20.814)

INFO  2020-06-08 11:35:59.927 [Log4J Redirect INFO-1] com.xcxcx.util.Log4JAppender$SystemOutProxy  - Hibernate: 
    /* dynamic native SQL query */ select
        rp.*
    from
        abcde.dbo.table1 pe,
        abcde.dbo.table2 rp 
    where
        pe.a = ? 
        and pe.b = ? 
        and rp.a = pe.a 
        and rp.b = pe.b 
        and rp.c = pe.c 

INFO  2020-06-08 11:36:00.098 [Log4J Redirect INFO-1] com.abcde.util.Log4JAppender$SystemOutProxy  - Hibernate: 
    select
        // columns defined for select
    from
        abcde.dbo.table2 table2i0_ 
    where
        table2i0_.a=? 
        and table2i0_.b=?
WARN  2020-06-08 11:36:00.277 [main] com.abcde.db.dbconnect.DBConnectUtil  - Exception during statement execution 
com.sybase.jdbc4.jdbc.SybSQLException: Implicit conversion from datatype 'VARCHAR' to 'INT' is not allowed.  Use the CONVERT function to run this query.
at com.sybase.jdbc4.tds.Tds.processEed(Tds.java:4119)
    at com.sybase.jdbc4.tds.Tds.nextResult(Tds.java:3235)
    at com.sybase.jdbc4.jdbc.ResultGetter.nextResult(ResultGetter.java:78)
    at com.sybase.jdbc4.jdbc.SybStatement.nextResult(SybStatement.java:294)
    at com.sybase.jdbc4.jdbc.SybStatement.nextResult(SybStatement.java:276)
    at com.sybase.jdbc4.jdbc.SybStatement.queryLoop(SybStatement.java:2643)
    at com.sybase.jdbc4.jdbc.SybStatement.executeQuery(SybStatement.java:2629)
    at com.sybase.jdbc4.jdbc.SybPreparedStatement.executeQuery(SybPreparedStatement.java:274)
RDM
  • 1,136
  • 3
  • 28
  • 50
  • Thank you Eklavya, How do I put that in the form of xml ? Like this: ` ` – RDM Jun 08 '20 at 15:50
  • For xml https://stackoverflow.com/a/45137516/4207306 – Eklavya Jun 08 '20 at 15:54
  • I saw that, it didn't work for me. I added the BasicBinder as TRACE in log4j.xml but didn't work. I already have org.hibernate set to TRACE ` ` – RDM Jun 08 '20 at 15:55
  • Also, https://docs.jboss.org/hibernate/orm/5.4/userguide/html_single/Hibernate_User_Guide.html#best-practices-logging, doesn't say anything about BasicBinder – RDM Jun 08 '20 at 15:55
  • 2
    Does this answer your question? [How to print a query string with parameter values when using Hibernate](https://stackoverflow.com/questions/1710476/how-to-print-a-query-string-with-parameter-values-when-using-hibernate) – Mandy Jun 08 '20 at 16:09

2 Answers2

1

In appication.properties under src/main/resources, place this

logging.level.org.hibernate.SQL=DEBUG
logging.level.org.hibernate.type.descriptor.sql.BasicBinder=TRACE

or

logging.level.org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl=TRACE

or

Spring use the logback by default so place the following logback.xml in classpath

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="SQL_CONSOLE" class="ch.qos.logback.core.ConsoleAppender" >
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
      <evaluator>        
        <matcher>
          <Name>allow</Name>
          <regex>.*Closing\sprepared\sstatement.*</regex>
        </matcher>
        <expression>allow.matches(formattedMessage)</expression>
      </evaluator>
      <OnMismatch>DENY</OnMismatch>
      <OnMatch>ACCEPT</OnMatch>
    </filter>
    <encoder>
        <pattern>---SQL[START]----\n%d{"yyyy-MM-dd'T'HH:mm:ss,SSS"} %replace(%msg){'Closing prepared statement',''}%n-----SQL[END]----\n</pattern>
        <outputPatternAsHeader>false</outputPatternAsHeader>
      </encoder>     
  </appender>
  <appender name="DEFAULT_CONSOLE" class="ch.qos.logback.core.ConsoleAppender" >
  <encoder>
        <pattern>%logger[0]: %msg%n</pattern>
        <outputPatternAsHeader>false</outputPatternAsHeader>
      </encoder>   
  </appender>
  <logger level="TRACE" name="org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl" additivity="false">
    <appender-ref ref="SQL_CONSOLE" />
  </logger>
  <root level="ERROR">
    <appender-ref ref="DEFAULT_CONSOLE" />
  </root>
</configuration>

Regex filter will filter out the necessary log and you can customize the output format in encoder.

zawhtut
  • 8,335
  • 5
  • 52
  • 76
0

You just need to make org.hibernate.sql to org.hibernate.SQL in your log4j.xml

In log4j.properties do below :

# logs the SQL statements
log4j.logger.org.hibernate.SQL=debug 

# Logs the JDBC parameters passed to a query
log4j.logger.org.hibernate.type=trace

In log4j.xml do below :

    <logger name="org.hibernate.SQL">
        <level value="DEBUG"/>
    </logger>
    <logger name="org.hibernate.type">
        <level value="TRACE"/>
    </logger>
Mandy
  • 163
  • 1
  • 9