G
George Potemkin
Guest
Friday's question. But at first the very long introduction (sorry). Self-service session crashed holding a latch: [2018/02/23@16:46:55.591+0600] P-6053 T-1 I WDOG 2462: (5028) SYSTEM ERROR: Releasing regular latch. latchId: 7 [2018/02/23@16:46:55.592+0600] P-6053 T-1 I WDOG 1104: (2522) User 2462 died holding 1 shared memory locks. It's very unexpected that the session held the GST latch but it's a different story. Ones of the first disconnected sessions were the background processes: [2018/02/23@16:46:55.591+0600] P-6051 T-1 I APW 1102: (453) Logout by xxxxxx on batch. [2018/02/23@16:46:55.593+0600] P-6055 T-1 I AIW 1105: (453) Logout by xxxxxx on batch. [2018/02/23@16:46:55.600+0600] P-6054 T-1 I BIW 1106: (2520) Stopped. [2018/02/23@16:46:55.687+0600] P-6053 T-1 F WDOG 1104: (1007) SYSTEM ERROR: unexpected wakeup from wait code -2, user 1104 [2018/02/23@16:46:55.687+0600] P-6053 T-1 I WDOG 1104: (439) ** Save file named core for analysis by Progress Software Corporation. [2018/02/23@16:46:55.687+0600] P-6053 T-1 I WDOG 1104: (453) Logout by xxxxxx on batch. [2018/02/23@16:46:55.691+0600] P-6050 T-1 I APW 1103: (453) Logout by xxxxxx on batch. [2018/02/23@16:46:57.820+0600] P-24168 T-1 I BROKER 0: (15192) The database will complete shutdown within approximately 60 seconds. [2018/02/23@16:46:57.821+0600] P-24168 T-1 I BROKER 0: (2249) Begin ABNORMAL shutdown code 2 Promon session started by dbmon script was disconnected a bit later and fortunately it gathered the information at the right time: 02/23/18 Activity: Summary 16:46:59 02/23/18 16:41 to 02/23/18 16:46 (5 min 8 sec) Event Total Per Sec |Event Total Per Sec Record Waits 11 0.0 |Active trans 217 Writes by APW 93 % Writes by BIW 58 % Writes by AIW 99 % DB Size: 3643 GB BI Size: 11 GB AI Size: 625 MB Empty blocks: 457 Free blocks: 52241 RM chain: 113 Buffer Hits 99 % Primary Hits 99 % Alternate Hits 99 % 0 Servers, 3897 Users (2392 Local, 1505 Remote, 750 Batch), 0 Apws "Status: Active Transactions" screen gave us the list of those 217 transactions. 188 transactions were in "Active" state and the rest 29 were in "Begin" state. 121 transactions created by SELF/ABL sessions. Only 10 sessions backed out their transactions (3 transactions in "Begin" state and 7 in "Active" state): [2018/02/23@16:47:04.576+0600] P-17891 T-1 I ABL 1315: (2252) Begin transaction backout. [2018/02/23@16:47:04.577+0600] P-17891 T-1 I ABL 1315: (2253) Transaction backout completed. ... [2018/02/23@16:47:05.364+0600] P-28364 T-1 I ABL 1602: (2252) Begin transaction backout. [2018/02/23@16:47:05.364+0600] P-28364 T-1 I ABL 1602: (2253) Transaction backout completed. Then db broker died as well: [2018/02/23@16:47:05.574+0600] P-24168 T-1 F BROKER 0: (1007) SYSTEM ERROR: unexpected wakeup from wait code -2, user 0 [2018/02/23@16:47:05.574+0600] P-24168 T-1 I BROKER 0: (439) ** Save file named core for analysis by Progress Software Corporation. [2018/02/23@16:47:05.574+0600] P-24168 T-1 I BROKER 0: (453) Logout by xxxxxx on batch. [2018/02/23@16:47:06.587+0600] P-24168 T-1 I BROKER : (16869) Removed shared memory with segment_id: 32 [2018/02/23@16:47:06.587+0600] P-24168 T-1 I BROKER : (16869) Removed shared memory with segment_id: 33 [2018/02/23@16:47:06.587+0600] P-24168 T-1 I BROKER : (16869) Removed shared memory with segment_id: 34 [2018/02/23@16:47:06.587+0600] P-24168 T-1 I BROKER : (334) Multi-user session end. There were another 2019 logout messages written to db log after "Multi-user session end". Among them there were the sessions with the active transactions: 02/23/18 Status: Active Transactions by user number for all tenants 16:46:59 Usr:Ten Name Domain Type Login time Tx start time Trans id BI RReads BI RWrites Trans State 2618 xxxxxx 0 SELF/ABL 02/23/18 09:29 02/23/18 16:37 1998135437 0 55 Active FWD 2804 yyyyyy 0 SELF/ABL 02/23/18 13:01 02/23/18 16:39 1998555745 0 55 Active FWD 3218 zzzzzz 0 SELF/ABL 02/23/18 11:34 02/23/18 16:43 1999277796 0 93 Active FWD [2018/02/23@16:52:58.527+0600] P-20577 T-1 I ABL 2618: (453) Logout by xxxxxx on /dev/pts/1414. [2018/02/23@17:02:18.414+0600] P-5030 T-1 I ABL 2804: (453) Logout by yyyyyy on /dev/pts/1283. [2018/02/23@17:05:10.474+0600] P-7933 T-1 I ABL 3218: (453) Logout by zzzzzz on /dev/pts/1480. They did not have the "transaction backout" messages. It's, of course, possible to start a database after a previous "multi-user session end" and the database was started. And logouts of the processes from previous multi-user session lasted next 18 minutes. End of long introduction. Short question: Did these old sessions with active transactions write their recovery notes to bi files after new multi-user session was started? New multi-user session wrote: BROKER 0: (12080) Begin Replication Redo Phase for 33 live transactions from 327680 . BROKER 0: (7163) Begin Physical Undo 256 transactions at block 341145 offset 16382 256 is more than the number of transactions at the beginning of shutdown. Unfortunately the customer did not use the -crTXDisplay parameter to start the database. So I don't know which transactions were undone.
Continue reading...
Continue reading...
