cancel
Showing results for 
Search instead for 
Did you mean: 

SAP IQ 16 Hang in the last phase of insert from ASE 15.7 using RLV

Former Member
0 Kudos

Problem description:

When I try to load 73K rows from ASE 15.7 to IQ 16.0 SP3 the IQ server ‘hang’ at the last phase of the insert (merge RLV store to main IQ dbspace).

Hang: The server stops responding; stop writing to iqmsg; and, I’m unable to stop the server using stop_iq; the only way to stop the server is to kill the process (on Unix).

Any suggestion on how to solve this issue will be appreciated.

My configuration

Adaptive Server Enterprise/15.7/EBF 21339 SMP SP101 /P/X64/Windows Server/ase157sp101/3439/64-bit/OPT/Thu Jun 06 12:11:05 2013

Sybase IQ/16.0.0.653/131122/P/sp03/Sun_Sparc/OS 5.10/64bit/2013-11-22 01:16:26  (8 cores)

How to reproduce the problem:

In ASE 15.7

Create and populate the following table:

CREATE TABLE dbo.MyTable  (

        Program                 varchar(3) NULL,

        EncNum                  varchar(12) NULL,

MRN                     varchar(8) NULL,

IntervalStartDtm varchar(19) NULL,

        IntervalEndDtm          varchar(19) NULL,

        IntervalType            varchar(50) NULL,

        IntervalDuration        numeric(19,4) NULL,

        PhysFirstName           varchar(50) NULL,

        PhysLastName            varchar(50) NULL,

        PhysNum                 varchar(6) NULL,

        Location                varchar(3) NULL,

        DiseaseSite             varchar(20) NULL,

        Priority                int NULL,

        DelayReason             int NULL,

        ExcludeFlag             varchar(1) NULL

        )

LOCK ALLPAGES

GO

I’d around 73,000 rows, you can populate the table with random data.

EndNum are of format ‘999999999999’

MRN number are of format ‘99999999’

On SAP IQ 16.0 SP3

Create the new RVL STORE

create dbspace IQ_RLVStore

   using file IQ_RLVFile1 '/dev/vx/rdsk/datadg/pdevtemp1' size 15360

IQ RLV STORE

Start Up Parameters

-n devDwIqSrvr

-x tcpip{port=4101}

-c  512m

-gc 20

-gd all

-gl all

-gm 100

-gn 150

-gp 4096

-ti 4400

-iqlm 4096

-iqmc 4096

-iqtc 4096

-iqgovern 100

-iqrlvmem 2048

-iqmsgsz 2047

-iqmsgnum 2

-xs http{port=8082}

Create the table

CREATE TABLE DBA. MyTable  (

        Program                 varchar(3) NULL,

        EncNum                  varchar(12) NULL,

MRN                     varchar(8) NULL,

IntervalStartDtm varchar(19) NULL,

        IntervalEndDtm          varchar(19) NULL,

        IntervalType            varchar(50) NULL,

        IntervalDuration        numeric(19,4) NULL,

        PhysFirstName           varchar(50) NULL,

        PhysLastName            varchar(50) NULL,

        PhysNum                 varchar(6) NULL,

        Location                varchar(3) NULL,

        DiseaseSite             varchar(20) NULL,

        Priority                integer NULL,

        DelayReason             integer NULL,

        ExcludeFlag             varchar(1) NULL IQ UNIQUE (255

        )

GO

set option public.SNAPSHOT_VERSIONING = 'Row-level'

set option public.RV_RESERVED_DBSPACE_MB = 500

alter table DBA. MyTable

  enable RLV STORE

On ASE 15.7

Create a new session (disconnect and reconnect)

Create the new server

sp_addserver 'devDwIqSrvr', ASIQ, 'ohdwdbdev01:4101'

Add and external login

sp_addexternlogin devDwIqSrvr, sa, DBA, myPassword

Create proxy a table

`

create proxy_table MyTable _proxy

at 'devDwIqSrvr.devDwIqDb.DBA. MyTable '

Execute

insert into dbo. MyTable _proxy

  select * from dbo. MyTable

In the 2 servers where I tested, the IQ server ‘hang’ after around 1 hrs.

Accepted Solutions (0)

Answers (2)

Answers (2)

Former Member
0 Kudos

Just an update.  To solve our problem we change the way how we load the data. for details you can refer to

c_baker
Employee
Employee
0 Kudos

You are probably running out of RLV memory.  Your approximate row length x the number of rows is more than the -iqrlvmem configuration.

When loading data using RLV, you must commit occasionally in order for the merge to occur to TLV pages.  As you are loading in a single transaction, no commit is occuring, so the merge cannot happen.

Since you are running this from the ASE side, you probably need to increase the -iqrlvmem configuration and/or reducing the batch size (using a 'where' clause, etc) to allow the merge to occur and free up RLV memory.

Chris

Former Member
0 Kudos

Hi Chris,

Thanks a lot for your help.

As per your suggestion, I increased the –iqrlvmem to 4096

And also,  set option public.RV_Auto_Merge_Eval_Interval = 1

But, still have the same behavior.

Here you can see the state of the IQ server just a few seconds before it hang.

select SpCount/2 from

sp_iqtransaction()

where TxnID = 119410926

SELECT TOTAL FROM sp_iqrlvmemory('myTable', 'DBA')

exec sp_iqstatus

sp_iqtransaction.SpCount/2   

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

72607.5   (approximate number of tables already loaded on the RLV part of the table)                     

1 record(s) selected [Fetch MetaData: 0ms] [Fetch Data: 0ms]

TOTAL

--------

252

1 record(s) selected [Fetch MetaData: 0ms] [Fetch Data: 0ms]

1 record(s) affected

Name Value

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

Sybase IQ (TM)                                Copyright (c) 1992-2013 by SAP AG or an SAP affiliate company. All rights reserved.

  Version: 16.0.0.653/131122/P/sp03/Sun_Sparc/OS 5.10/64bit/2013-11-22 01:16:26               

  Time Now:                                    2014-04-01 15:10:00.672                                                            

  Build Time:                                  2013-11-22 01:16:26

  File Format:                                 23 on 03/18/1999                                                                   

  Server mode:                                 IQ Server

  Catalog Format:                              2                                                                                  

  Stored Procedure Revision:                   1

  Page Size:                                   131072/8192blksz/16bpp

  Number of Main DB Files:                     4

  Main Store Out Of Space:                     N

  Number of Cache Dbspace Files:               0

  Number of Shared Temp DB Files:              0

  Shared Temp Store Out Of Space:              N

  Number of Local Temp DB Files:               1

  Local Temp Store Out Of Space:               N

  DB Blocks: 1-8716280 IQ_SYSTEM_MAIN_16384

  DB Blocks: 9408960-18125239                  IQ_SYSTEM_MAIN_2_16387

  DB Blocks: 19863360-22484791                 SF1

  DB Blocks: 22999680-24965759                 IQ_RLVFile1

  Local Temp Blocks: 1-1966072                 IQ_SYSTEM_TEMP_16388

  Create Time:                                 2011-08-07 09:24:11.169

  Update Time:                                 2014-04-01 14:52:51.422

  Main IQ Buffers:                             32652, 4096Mb                                                                      

  Temporary IQ Buffers:                        32652, 4096Mb

  Main IQ Blocks Used:                         3144428 of 21993858, 14%=23Gb, Max Block#: 23117643                                

  Cache Dbspace IQ Blocks Used:                0 of 0, 0%=0Mb, Max Block#: 0

  Shared Temporary IQ Blocks Used:             0 of 0, 0%=0Mb, Max Block#: 0

  Local Temporary IQ Blocks Used:              113 of 1940472, 0%=0Mb, Max Block#: 241                                            

  Main Reserved Blocks Available:              26214 of 26214, 100%=204Mb

  Shared Temporary Reserved Blocks Available:  0 of 0, 0%=0Mb

  Local Temporary Reserved Blocks Available:   25600 of 25600, 100%=200Mb

  IQ Dynamic Memory:                           Current: 9502mb, Max: 9526mb                                                       

  Main IQ Buffers:                             Used: 2251, Locked: 0

  Temporary IQ Buffers:                        Used: 7, Locked: 0                                                                 

  Main IQ I/O:                                 I: L18549/P79 O: C2336/D2740/P2581 D:519 C:39.7                                    

  Temporary IQ I/O:                            I: L110366/P0 O: C2568/D2592/P32 D:2561 C:97.1                                     

  Other Versions:                              1 = 69Mb

  Active Txn Versions:                         0 = C:0Mb/D:0Mb                                                                    

  Last Full Backup ID:                         119254657

  Last Full Backup Time:                       2014-03-30 19:00:00                                                                

  Last Backup ID:                              119415062

  Last Backup Type:                            INCR                                                                               

  Last Backup Time:                            2014-04-01 15:00:00

  DB Updated:                                  1                                                                                  

  Blocks in next ISF Backup:                   8928 Blocks: =69Mb

  Blocks in next ISI Backup:                   0 Blocks: =0Mb

  IQ large memory space:                       4096Mb

  IQ large memory flexible percentage:         50

  IQ large memory flexible used:               0Mb

  IQ large memory inflexible percentage:       90

  IQ large memory inflexible used:             0Mb

  IQ large memory anti-starvation percentage:  50

  DB File Encryption Status:                   OFF

  RLV memory limit:                            4096Mb

  RLV memory used:                             348Mb

56 record(s) selected [Fetch MetaData: 1ms] [Fetch Data: 2ms]

[Executed: 01/04/2014 3:10:01 PM] [Execution: 140ms]

Follow the last records on the iqmsg file (Note the frequency in with the last records are written):

  1. I. 04/01 15:10:00. 0000000027 Dictionary: 17247
  2. I. 04/01 15:10:00. 0000000027                                        nullBitMap:                      132232
  3. I. 04/01 15:10:00. 0000000027                                        SubFragArray*s:                      64
  4. I. 04/01 15:10:00. 0000000027 nullWriter*: 24
  5. I. 04/01 15:10:00. 0000000027 ridMap:                            24688
  6. I. 04/01 15:10:00. 0000000027 allocatedMemory: 16777216
  7. I. 04/01 15:10:00. 0000000027 inserter*: 1072
  8. I. 04/01 15:10:00. 0000000027         Size of Tkn-ColFrag for Priority: 88
  9. I. 04/01 15:10:00. 0000000027 Dictionary: 9471
  10. I. 04/01 15:10:00. 0000000027                                        nullBitMap:                      132232
  11. I. 04/01 15:10:00. 0000000027                                        SubFragArray*s:                      64
  12. I. 04/01 15:10:00. 0000000027 nullWriter*: 24
  13. I. 04/01 15:10:00. 0000000027 ridMap: 24688
  14. I. 04/01 15:10:00. 0000000027 allocatedMemory: 16777216
  15. I. 04/01 15:10:00. 0000000027 inserter*: 1072
  16. I. 04/01 15:10:00. 0000000027         Size of Tkn-ColFrag for DelayReason:                   88
  17. I. 04/01 15:10:00. 0000000027 Dictionary: 9471
  18. I. 04/01 15:10:00. 0000000027 ColFrag for ExcludeFlag:                                64
  19. I. 04/01 15:10:00. 0000000027                                        nullBitMap:                         992
  20. I. 04/01 15:10:00. 0000000027                                        SubFragArray*s:                      64
  21. I. 04/01 15:10:00. 0000000027 nullWriter*: 24
  22. I. 04/01 15:10:00. 0000000027 ridMap: 24688
  23. I. 04/01 15:10:00. 0000000027 allocatedMemory: 262144
  24. I. 04/01 15:10:00. 0000000027 inserter*: 1072
  25. I. 04/01 15:10:00. 0000000027 PseudoCol frag:                                64
  26. I. 04/01 15:10:00. 0000000027                                        nullBitMap:                      132232
  27. I. 04/01 15:10:00. 0000000027                                        SubFragArray*s:                      64
  28. I. 04/01 15:10:00. 0000000027             SubFragmentFixColumn:                      96
  29. I. 04/01 15:10:00. 0000000027                 nullWriter*:                           24
  30. I. 04/01 15:10:00. 0000000027 ridMap: 24688
  31. I. 04/01 15:10:00. 0000000027 allocatedMemory: 16777216
  32. I. 04/01 15:10:00. 0000000027 inserter*: 1072
  33. I. 04/01 15:10:00. 0000000027     ColStore array sizeof: 840
  34. I. 04/01 15:10:00. 0000000027     Pseudo ColStore sizeof: 48
  35. I. 04/01 15:10:00. 0000000027 Total: 263865842
  36. I. 04/01 15:10:00. 0000000027 ExistanceBM:                                            0
  37. I. 04/01 15:10:00. 0000000027 ------------------------------------------------
  38. I. 04/01 15:10:00. 0000000027 Cmt 119415977
  39. I. 04/01 15:10:00. 0000000027 PostCmt 0
  40. I. 04/01 15:10:00. 0000000027 Txn 119415978 0 119415978
  41. I. 04/01 15:10:00. 0000000027 Cmt 119415979
  42. I. 04/01 15:10:00. 0000000027 PostCmt 0
  43. I. 04/01 15:10:02. 0000001885 Txn 119415980 0 119415980
  44. I. 04/01 15:10:02. 0000001885 Cmt 119415981
  45. I. 04/01 15:10:02. 0000001885 PostCmt 0
  46. I. 04/01 15:10:04. 0000001886 Txn 119415982 0 119415982
  47. I. 04/01 15:10:04. 0000001886 Cmt 119415983
  48. I. 04/01 15:10:04. 0000001886 PostCmt 0
  49. I. 04/01 15:10:06. 0000001887 TabFrag sizeof: 96
  50. I. 04/01 15:10:06. 0000001887 ColFrag*s sizeof: 120
  51. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  52. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  53. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  54. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  55. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  56. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  57. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for Program: 88
  58. I. 04/01 15:10:06. 0000001887 Dictionary: 10535
  59. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  60. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  61. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  62. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  63. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  64. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  65. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for EncNum: 88
  66. I. 04/01 15:10:06. 0000001887 Dictionary: 2972353
  67. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  68. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  69. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  70. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  71. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  72. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  73. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for MRN: 88
  74. I. 04/01 15:10:06. 0000001887 Dictionary: 2716353
  75. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  76. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  77. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  78. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  79. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  80. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  81. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for IntervalStartDtm: 88
  82. I. 04/01 15:10:06. 0000001887 Dictionary: 1656530
  83. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  84. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  85. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  86. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  87. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  88. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  89. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for IntervalEndDtm:                   88
  90. I. 04/01 15:10:06. 0000001887 Dictionary:                           3393473
  91. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  92. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  93. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  94. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  95. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  96. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  97. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for IntervalType:                   88
  98. I. 04/01 15:10:06. 0000001887 Dictionary: 10535
  99. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  100. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  101. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  102. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  103. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  104. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  105. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for IntervalDuration:                   88
  106. I. 04/01 15:10:06. 0000001887 Dictionary: 140422
  107. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  108. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  109. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  110. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  111. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  112. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  113. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for PhysFirstName:                   88
  114. I. 04/01 15:10:06. 0000001887 Dictionary: 14687
  115. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  116. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  117. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  118. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  119. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  120. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  121. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for PhysLastName:                   88
  122. I. 04/01 15:10:06. 0000001887 Dictionary:                             14687
  123. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                      132232
  124. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  125. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  126. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  127. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  128. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  129. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for PhysNum: 88
  130. I. 04/01 15:10:06. 0000001887 Dictionary: 10535
  131. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  132. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  133. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  134. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  135. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  136. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  137. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for Location:                   88
  138. I. 04/01 15:10:06. 0000001887 Dictionary: 10535
  139. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  140. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  141. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  142. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  143. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  144. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  145. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for DiseaseSite:                   88
  146. I. 04/01 15:10:06. 0000001887 Dictionary:                             17247
  147. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                      132232
  148. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  149. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  150. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  151. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  152. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  153. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for Priority: 88
  154. I. 04/01 15:10:06. 0000001887 Dictionary: 9471
  155. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                      132232
  156. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  157. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  158. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  159. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  160. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  161. I. 04/01 15:10:06. 0000001887         Size of Tkn-ColFrag for DelayReason: 88
  162. I. 04/01 15:10:06. 0000001887 Dictionary: 9471
  163. I. 04/01 15:10:06. 0000001887 ColFrag for ExcludeFlag:                                64
  164. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                         992
  165. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  166. I. 04/01 15:10:06. 0000001887 nullWriter*: 24
  167. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  168. I. 04/01 15:10:06. 0000001887 allocatedMemory: 262144
  169. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  170. I. 04/01 15:10:06. 0000001887 PseudoCol frag:                                64
  171. I. 04/01 15:10:06. 0000001887                                        nullBitMap:                      132232
  172. I. 04/01 15:10:06. 0000001887                                        SubFragArray*s:                      64
  173. I. 04/01 15:10:06. 0000001887             SubFragmentFixColumn:                      96
  174. I. 04/01 15:10:06. 0000001887                 nullWriter*:                           24
  175. I. 04/01 15:10:06. 0000001887 ridMap: 24688
  176. I. 04/01 15:10:06. 0000001887 allocatedMemory: 16777216
  177. I. 04/01 15:10:06. 0000001887 inserter*: 1072
  178. I. 04/01 15:10:06. 0000001888 Txn 119415984 0 119415984
  179. I. 04/01 15:10:06. 0000001888 Cmt 119415985
  180. I. 04/01 15:10:06. 0000001888 PostCmt 0
  181. I. 04/01 15:10:08. 0000001889 Txn 119415986 0 119415986
  182. I. 04/01 15:10:08. 0000001889 Cmt 119415987
  183. I. 04/01 15:10:08. 0000001889 PostCmt 0
  184. I. 04/01 15:10:10. 0000001890 Txn 119415988 0 119415988
  185. I. 04/01 15:10:10. 0000001890 Cmt 119415989
  186. I. 04/01 15:10:10. 0000001890 PostCmt 0
  187. I. 04/01 15:10:12. 0000001891 Txn 119415990 0 119415990
  188. I. 04/01 15:10:12. 0000001891 Cmt 119415991
  189. I. 04/01 15:10:12. 0000001891 PostCmt 0
  190. I. 04/01 15:10:14. 0000001892 Txn 119415992 0 119415992
  191. I. 04/01 15:10:14. 0000001892 Cmt 119415993
  192. I. 04/01 15:10:14. 0000001892 PostCmt 0
  193. I. 04/01 15:10:35. 0000000000 Cancellation request received:  SA connHandle: 1  SA connID: 19 IQ connID: 0000000019  User: DBA
  194. I. 04/01 15:10:55. 0000000000 Cancellation request received:  SA connHandle: 1  SA connID: 19 IQ connID: 0000000019  User: DBA
  195. I. 04/01 15:10:55. 0000001894 Collation ISO_BINENG, Case Respect, Blank Padding On, Comparisons are Binary
  196. I. 04/01 15:12:55. 0000000000 Cancellation request received: 
  197. I. 04/01 15:13:31. 0000001897 Collation ISO_BINENG, Case Respect, Blank Padding On, Comparisons are Binary
  198. I. 04/01 15:14:55. 0000000000 Cancellation request received: 
  199. I. 04/01 15:15:31. 0000000000 Cancellation request received: 
  200. I. 04/01 15:16:31. 0000001898 Collation ISO_BINENG, Case Respect, Blank Padding On, Comparisons are Binary
Former Member
0 Kudos

Do you have any left over RLV transaction? After you reboot IQ do you see any locks? check with sp_iqlocks.... (Shocked!... You will have orphan trasncation event after IQ reboot)

The tail of iqmsg file has no meaning. Either search for lasst occurance of TableName in iqmsg file or 'Mrg B' and 'Except' string and the messages around this.

or just post o/p from all available IQMSG files. You may not have info in lastest file if file is being rotated. Worth to search messages for last few days.

egrep 'Mrg B|Excep|youtablename' your.iqmsg

Abhijit

Former Member
0 Kudos

Hi Abhijit,

Thanks a lot for your help.

After the IQ reboot I have an Intent lock on the table, but I think this is normal and associated with the RLV process.

conn_name conn_id     user_id     table_type     creator table_name          index_id     lock_class     lock_duration     lock_type     row_identifier     row_range   

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

RLV_CONN_T1290 1000000004              BASE           DBA         IClinicalWaitTimes  (null) Table          Transaction       Intent        (null)             (null)      

1 record(s) selected [Fetch MetaData: 0ms] [Fetch Data: 0ms]

[Executed: 02/04/2014 10:12:29 AM] [Execution: 7ms]

Also, where I execute the search on the iqmsg I cannot find any Mrg of Except, but I can see some record of the RLV starting 14:53, look like keep trying until 15:10, I killed the IQ process at 15:32 and restarted the database;  at that time (15:25) I can see a recovery and the a RLV dump (15:26)

Any idea about what is going on?

(sybase@ohdwdbdev01)/IQ/Data/dev->egrep 'Mrg|xcept|Clin' devDwIqDb.iqmsg | more

  1. I. 03/26 11:36:59. 0000000001 0000000160 Added table 1290 ('IClinicalWaitTimes'), stream 2 to the recovery session table
  2. I. 04/01 12:47:15. 0000000001 0000000160 Added table 1290 ('IClinicalWaitTimes'), stream 2 to the recovery session table
  3. I. 04/01 14:10:02. 0000000001 0000000160 Added table 1290 ('IClinicalWaitTimes'), stream 2 to the recovery session table
  4. I. 04/01 14:18:53. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  5. I. 04/01 14:34:53. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  6. I. 04/01 14:43:32. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  7. I. 04/01 14:46:22. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  8. I. 04/01 14:47:00. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  9. I. 04/01 14:53:56. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  10. I. 04/01 14:56:10. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  11. I. 04/01 14:57:35. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  12. I. 04/01 15:00:02. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  13. I. 04/01 15:00:52. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  14. I. 04/01 15:02:40. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  15. I. 04/01 15:04:10. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  16. I. 04/01 15:04:26. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  17. I. 04/01 15:04:43. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  18. I. 04/01 15:05:02. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  19. I. 04/01 15:06:11. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  20. I. 04/01 15:06:30. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  21. I. 04/01 15:06:55. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  22. I. 04/01 15:07:08. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  23. I. 04/01 15:07:27. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  24. I. 04/01 15:08:06. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  25. I. 04/01 15:08:21. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  26. I. 04/01 15:08:40. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  27. I. 04/01 15:08:51. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  28. I. 04/01 15:09:20. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  29. I. 04/01 15:09:40. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  30. I. 04/01 15:09:45. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  31. I. 04/01 15:10:00. 0000000027 Starting RLV memory dump of table IClinicalWaitTimes (1290)
  32. I. 04/01 15:25:47. 0000000001 0000000160 Added table 1290 ('IClinicalWaitTimes'), stream 2 to the recovery session table
  33. I. 04/01 15:26:40. 0000000023 Starting RLV memory dump of table IClinicalWaitTimes (1290)
Former Member
0 Kudos

Sorry for the typo, should read:

I killed the IQ process at 15:12 and restarted the database

Former Member
0 Kudos

Disable and re-enable RLV for table which you see lock and you should be alright.

Tx, Abhi

Former Member
0 Kudos

Thanks, I tested your suggestion but still have the same behavior,  any more ideas?

Former Member
0 Kudos

Do you see any new messages in iqmsg file?

Before testing RLV, Did you checked if you are able to insert a single record in IQ proxy table from ASE without enabling RLV?

1. disable RLV for the table.

2. reboot IQ -- Check any messages reported

3. Test - inserting a single record from ASE to IQ proxy table. You may use 'insert into MyTable_proxy select top 1 from MyTable'

4. If succesful enable RLV and try to insert few records first.

Also set following options until you have success on RLV,

SET OPTION PUBLIC.RV_MERGE_TABLE_NUMROWS=10000;   --- 10000 rows

SET OPTION PUBLIC.RV_AUTO_MERGE_EVAL_INTERVAL='1’;   --- 1 minute

Regards,

Abhi

Former Member
0 Kudos

Hi Abhijit,

I try it that before, smaller loads (under 10K rows or over 50K rows but with less columns) works ok,  But I think 72K rows for the table in use should not be a problem.  Look like the merge process never start (it is in some kind of starvation state).

I now that one possible solution of the problem is reduce the number of rows per insert, but, in IQ 15.2 the same load take around 1 hr.  In IQ 16 I'm not able to make it finish.

Thanks a lot!

Uvernes