Db2

  • 1.  Timeouts on busy database

    IBM Champion
    Posted Wed September 02, 2020 05:23 AM
    Hi,

    I frequently get on a busy system this error message JCC -4499 on the database connection

    (BTW: The upper part is cut off and is hence not legible. The only way to see more of the message would probably be to define a bunch of dummy database entries to bring my failing one down in the list!)

    In the monitor.0 logfile, I can find these details. I have even tried to reduce the number of lines retrieved.

    ### SQL: WITH APPL_INFO AS ( SELECT DISTINCT T.TBSP_ID, T.TAB_FILE_ID, RTRIM(T.TABSCHEMA) AS TABSCHEMA, RTRIM(T.TABNAME) AS TABNAME, T.DATA_PARTITION_ID AS DATA_PARTITION_ID, T.MEMBER AS MEMBER FROM TABLE( MON_GET_LOCKS(NULL,-2)) AS L LEFT OUTER JOIN TABLE( MON_GET_TABLE(NULL,NULL,-2)) AS T ON L.TBSP_ID=T.TBSP_ID AND L.TAB_FILE_ID = T.TAB_FILE_ID AND T.MEMBER = L.MEMBER WITH UR ) SELECT L.APPLICATION_HANDLE AS APPLICATION_HANDLE, L.MEMBER AS MEMBER, C.SESSION_AUTH_ID AS SESSION_AUTH_ID, C.APPLICATION_NAME AS APPLICATION_NAME, (CURRENT TIMESTAMP - C.UOW_START_TIME) AS LOCK_ELAPSED_TIME, C.WORKLOAD_OCCURRENCE_STATE AS WORKLOAD_OCCURRENCE_STATE, L.LOCK_STATUS AS LOCK_STATUS, L.LOCK_MODE AS LOCK_MODE, L.LOCK_NAME AS LOCK_NAME, L.LOCK_OBJECT_TYPE AS LOCK_OBJECT_TYPE, L.LOCK_CURRENT_MODE AS LOCK_CURRENT_MODE, C.NUM_LOCKS_HELD AS NUM_LOCKS_HELD, C.LOCK_WAITS AS LOCK_WAITS, C.LOCK_WAIT_TIME AS LOCK_WAIT_TIME, CASE WHEN L.LOCK_STATUS = 'G' THEN substr2(B.STMT_TEXT, 0, 32000) ELSE substr2(A.STMT_TEXT, 0, 32000) END AS STMT_TEXT, RTRIM(APPL_INFO.TABSCHEMA) AS TABSCHEMA, RTRIM(APPL_INFO.TABNAME) AS TABNAME, APPL_INFO.DATA_PARTITION_ID AS DATA_PARTITION_ID FROM TABLE( MON_GET_LOCKS(NULL,-2)) AS L LEFT OUTER JOIN TABLE( MON_GET_CONNECTION(NULL,-2)) AS C ON ( L.MEMBER = C.MEMBER AND L.APPLICATION_HANDLE = C.APPLICATION_HANDLE) LEFT OUTER JOIN TABLE( MON_GET_PKG_CACHE_STMT(NULL,NULL,NULL,-2)) AS B ON ( C.LAST_EXECUTABLE_ID = B.EXECUTABLE_ID AND B.MEMBER = C.MEMBER) LEFT OUTER JOIN TABLE( MON_GET_ACTIVITY(NULL,-2)) AS A ON ( L.MEMBER = A.MEMBER AND L.APPLICATION_HANDLE = A.APPLICATION_HANDLE) LEFT OUTER JOIN APPL_INFO ON L.TBSP_ID=APPL_INFO.TBSP_ID AND L.TAB_FILE_ID = APPL_INFO.TAB_FILE_ID AND L.MEMBER = APPL_INFO.MEMBER WHERE L.LOCK_STATUS IN ('G','W','C') AND (C.LOCK_WAIT_TIME > 30000 OR (CURRENT TIMESTAMP - C.UOW_START_TIME)*1000 > ?) FETCH FIRST 100 ROWS ONLY WITH UR
    ### Cause: com.ibm.db2.jcc.am.DisconnectNonTransientConnectionException: [jcc][t4][2030][11211][4.26.14] A communication error occurred during operations on the connection's underlying socket, socket input stream,
    or socket output stream. Error location: Query timeout check. Message: Query timed out. ERRORCODE=-4499, SQLSTATE=08001
    at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:150)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)
    at org.apache.ibatis.binding.MapperMethod.executeForMany(MapperMethod.java:137)
    at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:75)
    at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59)
    at com.sun.proxy.$Proxy326.collect100504(Unknown Source)
    at com.ibm.aps.tools.monitor.collector.mybatis.mapper.LocksMapper.collect(LocksMapper.java:41)
    at java.lang.invoke.ReceiverBoundHandle.invokeExact_thunkArchetype_L(ReceiverBoundHandle.java:172)
    at java.lang.invoke.AsTypeHandle.invokeExact_thunkArchetype_X(AsTypeHandle.java:49)
    at java.lang.invoke.InvokeGenericHandle.invokeExact_thunkArchetype_X(InvokeGenericHandle.java:88)
    at java.lang.invoke.SpreadHandle.invokeExact_thunkArchetype_X(SpreadHandle.java:100)
    at java.lang.invoke.MethodHandle.invokeWithArguments(MethodHandle.java:483)
    at org.apache.ibatis.binding.MapperProxy.invokeDefaultMethod(MapperProxy.java:84)
    at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:53)
    at com.sun.proxy.$Proxy326.collect(Unknown Source)
    at com.ibm.aps.tools.monitor.collector.consumer.MonitorCollectorConsumer.collect(MonitorCollectorConsumer.java:619)
    at com.ibm.aps.tools.monitor.collector.consumer.MonitorCollectorConsumer.run(MonitorCollectorConsumer.java:280)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.lang.Thread.run(Thread.java:818)
    Caused by: com.ibm.db2.jcc.am.DisconnectNonTransientConnectionException: [jcc][t4][2030][11211][4.26.14] A communication error occurred during operations on the connection's underlying socket, socket input stream,
    or socket output stream. Error location: Query timeout check. Message: Query timed out. ERRORCODE=-4499, SQLSTATE=08001
    at com.ibm.db2.jcc.am.b7.a(b7.java:338)
    at com.ibm.db2.jcc.t4.a.a(a.java:572)
    at com.ibm.db2.jcc.t4.a.a(a.java:556)
    at com.ibm.db2.jcc.t4.b.l(b.java:7727)


    If I execute this query manually from db2cmd, I have no issues and get results without timeouts. DMC seems to have an issue there.
    Also I wonder, if DMC really tries to do a reconnect in the background (probably, but not obvious).
    If I click on the database, I can check the connection settings, which are correct.

    In such a state, no other metrics can be accessed or shown.

    Kind regards

    ------------------------------
    Roland Schock
    Distinguished Engineer
    ARS Computer und Consulting GmbH
    Muenchen
    ------------------------------

    #Db2


  • 2.  RE: Timeouts on busy database

    IBM Champion
    Posted Thu September 03, 2020 03:10 AM
    The worst part of it is, DMC is completely unusable in such a case. You cannot even access other data, which gets collected according to the logs.
    If you click on the database to get to the details page, you just can click on ok to verify the connection settings or cancel to back out.

    When and how does DMC reconnect to the database? Does it at all? Or does DMC wait until the connection settings were re-confirmed?
    We could need a reconnect button next to the database entry. Or even an option to display historic data.

    ------------------------------
    Roland Schock
    Distinguished Engineer
    ARS Computer und Consulting GmbH
    Muenchen
    ------------------------------



  • 3.  RE: Timeouts on busy database

    Posted Thu September 03, 2020 11:18 AM
    Edited by System Fri January 20, 2023 04:14 PM

    Hi Roland, 

    This is a query timeout limit, defined in their Jdbc connection settings.  I believe they set some sort of limit,  to avoid queries  waiting forever, or too much time. 

    You said,  you can run the query from db2cmd line directly.   but how long does it takes ?  db2-CLP/db2cmd nas no default query timeout settings defined,  so basically it waits (forever) untill the query gets completed. 


    I have faced DMC/DSM query timeouts in the past as well ,  in busy heavy workload systems.  I believe DSM/DMC should expose this default query timeout setting in the console,  (db connection profile setting),  so we can best tune it, based on needs..  )  I am pretty sure some dbs will required to have a higher query timeout limits than the others..  But I am not sure of what value they are using (hardcoded) 

    Regards 



    ------------------------------
    Samuel Pizarro
    ------------------------------



  • 4.  RE: Timeouts on busy database

    Posted Tue September 08, 2020 10:37 PM
    Hi Roland and Samuel,

    Thanks for bringing up this issue. I've created a git issue to track it: https://github.ibm.com/tools-for-aps/zh/issues/20241

    Will ask dev team to investigate and see what we can do to improve it.

    ------------------------------
    KAI DING
    ------------------------------



  • 5.  RE: Timeouts on busy database

    IBM Champion
    Posted Thu September 03, 2020 12:28 PM

    Hi Roland & DMC Team,

    I seem to run into the same issue but I would not say that my system is very busy, rather the opposite. When I test the connection I get a success but immediately when I go to the database page it flips to disconnected and displays a similar message as Roland has posted. It seems to be a different query but the stack trace pretty much looks the same.

    ### Error querying database.  Cause: com.ibm.db2.jcc.am.DisconnectNonTransientConnectionException: [jcc][t4][2030][11211][4.26.14] A communication error occu
    rred during operations on the connection's underlying socket, socket input stream,
    or socket output stream.  Error location: Query timeout check.  Message: Query timed out. ERRORCODE=-4499, SQLSTATE=08001
    ### The error may exist in com/ibm/aps/tools/alert/log/mapper/AlertLogMapper.xml
    ### The error may involve com.ibm.aps.tools.alert.log.mapper.AlertLogMapper.doCollect
    ### The error occurred while handling results
    ### SQL: WITH UNICODE_FIX(X) AS (SELECT NULL FROM SYSIBM.SYSDUMMY1)   SELECT member, msgnum, SUBSTR(MSG, 1, 2047) as msg, TIMESTAMP as msgCreateTime, FUNCTIO
    N as functionName, DBNAME as dbname from    (    SELECT member, msgnum, MSG, TIMESTAMP , FUNCTION , DBNAME ,     ROW_NUMBER() OVER (PARTITION BY msgnum ORDER
     BY TIMESTAMP desc) AS INDEX    FROM TABLE (PD_GET_DIAG_HIST('MAIN', '', '', CAST(? as TIMESTAMP), CAST(? as TIMESTAMP)) )       WHERE (MSGTYPE = 'ADM') AND
    (MSGNUM IN (1813, 1814, 1848, 1540, 1542)) AND (DBNAME = ?)    ) AS T WHERE T.INDEX = 1
    ### Cause: com.ibm.db2.jcc.am.DisconnectNonTransientConnectionException: [jcc][t4][2030][11211][4.26.14] A communication error occurred during operations on
    the connection's underlying socket, socket input stream,
    or socket output stream.  Error location: Query timeout check.  Message: Query timed out. ERRORCODE=-4499, SQLSTATE=08001
            at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
            at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:150)
            at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)
            at org.apache.ibatis.binding.MapperMethod.executeForMany(MapperMethod.java:137)
            at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:75)
            at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59)
            at com.sun.proxy.$Proxy284.doCollect(Unknown Source)
            at com.ibm.aps.tools.alert.log.mapper.AlertLogMapper.collect(AlertLogMapper.java:58)
            at java.lang.invoke.ReceiverBoundHandle.invokeExact_thunkArchetype_L(ReceiverBoundHandle.java:172)
            at java.lang.invoke.AsTypeHandle.invokeExact_thunkArchetype_X(AsTypeHandle.java:49)
            at java.lang.invoke.InvokeGenericHandle.invokeExact_thunkArchetype_X(InvokeGenericHandle.java:88)
            at java.lang.invoke.SpreadHandle.invokeExact_thunkArchetype_X(SpreadHandle.java:100)
            at java.lang.invoke.MethodHandle.invokeWithArguments(MethodHandle.java:483)
            at org.apache.ibatis.binding.MapperProxy.invokeDefaultMethod(MapperProxy.java:84)
            at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:53)
            at com.sun.proxy.$Proxy284.collect(Unknown Source)
            at com.ibm.aps.tools.monitor.collector.consumer.MonitorCollectorConsumer.collect(MonitorCollectorConsumer.java:619)
            at com.ibm.aps.tools.monitor.collector.consumer.MonitorCollectorConsumer.run(MonitorCollectorConsumer.java:280)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
            at java.lang.Thread.run(Thread.java:818)
    Caused by: com.ibm.db2.jcc.am.DisconnectNonTransientConnectionException: [jcc][t4][2030][11211][4.26.14] A communication error occurred during operations on the connection's underlying socket, socket input stream,
    or socket output stream.  Error location: Query timeout check.  Message: Query timed out. ERRORCODE=-4499, SQLSTATE=08001
            at com.ibm.db2.jcc.am.b7.a(b7.java:338)
            at com.ibm.db2.jcc.t4.a.a(a.java:572)
            at com.ibm.db2.jcc.t4.a.a(a.java:556)
            at com.ibm.db2.jcc.t4.b.l(b.java:7727)
            at com.ibm.db2.jcc.t4.a.y(a.java:1705)



    ------------------------------
    Sven Heidorn
    ------------------------------



  • 6.  RE: Timeouts on busy database

    Posted Thu September 03, 2020 03:50 PM

    Hi Sven

    your case it's searching db2diag.log and it seems itt's taking a long time to parse it..   

    How big is your db2diag.log file in this particular DB ?   If too big,  this could explain why you are facing timeouts on this query.  

    If your db2diag.log is getting too big,  you need to implement regular archiving  (db2diag -A)  in order to create a new one in a regular basis  (once a week for example). 

    Another approach is to set a db2diag size limit in dbm-cfg setting, which will perform the logs rotation automatically when the size is reached. 




    ------------------------------
    Samuel Pizarro
    ------------------------------