[MCOL-5148] Large transaction did not rollback on ColumnStore startup (Docker container) Created: 2022-06-22  Updated: 2023-10-27  Resolved: 2023-10-27

Status: Closed
Project: MariaDB ColumnStore
Component/s: DDLProc
Affects Version/s: 6.4.1
Fix Version/s: Icebox

Type: Bug Priority: Major
Reporter: Daniel Lee (Inactive) Assignee: Leonid Fedorov
Resolution: Won't Fix Votes: 0
Labels: None
Environment:

Docker container


 Description   

Build tested: 6.4.1-1 (#4623)

This issue is discovered while testing MCOL-5105.
This issue occurs on Docker containers only, not on VMs.

1. set autocommit=0
2. update 1 billion rows
3. mcsShutdown
4. mcsStart

When the system shutdown, the transaction remained. During startup, DMLProc suppose to rollback the transaction, but all updated rows were committed.

According tot he debug.log, rollback finished immediate, while it should take more than 10 minutes.

debug.log

Jun 10 20:04:37 s0 dmlpackageproc[2225]: 37.347951 |15|7|0| D 21 CAL0001: Start SQL statement:  update t1 set cinteger=1;|mytest|  
Jun 10 20:04:37 s0 ExeMgr[2201]: 37.378452 |15|0|0| D 16 CAL0041: Start SQL statement: update t1 set cinteger=1; ||
 
Jun 10 20:18:25 s0 dmlpackageproc[2225]: 25.404298 |15|7|0| D 21 CAL0001: End SQL statement   
Jun 10 20:18:27 s0 ExeMgr[2201]: 27.248494 |15|0|0| D 16 CAL0042: End SQL statement
 
Jun 10 20:18:47 s0 DMLProc[2225]: 47.315745 |0|0|0| I 20 CAL0002: DMLProc has been told to rollback all DML transactions. 
Jun 10 20:19:47 s0 messagequeue[2156]: 47.157425 |0|0|0| W 31 CAL0000: Client read close socket for InetStreamSocket::readToMagic(): I/O error1: rc-1; poll signal interrupt ( POLLHUP POLLERR )        
Jun 10 20:19:47 s0 controllernode[2156]: 47.160338 |0|0|0| C 29 CAL0000: DBRM Controller: Network error reading from node 1.  Reading response to command 91, length 29.  Will see if retry is possible.         
Jun 10 20:19:47 s0 StorageManager[2122]: SessionManager Caught Signal 15
 
Jun 10 20:19:47 s0 StorageManager[2122]: Shutdown StorageManager...
 
Jun 10 20:19:47 s0 StorageManager[2122]: StorageManager Shutdown Complete.
 
Jun 10 20:19:47 s0 messagequeue[2156]: 47.317660 |0|0|0| W 31 CAL0000: MessageQueueClient::write: error writing 1 bytes to IOSocket: sd: 4 inet: 172.17.0.2 port: 8700. Socket error was InetStreamSocket::write error: Broken pipe -- write from InetStreamSocket: sd: 4 inet: 172.17.0.2 port: 8700#012         
Jun 10 20:19:47 s0 controllernode[2156]: 47.317745 |0|0|0| C 29 CAL0000: DBRM Controller: undo(): warning, could not contact worker number 1#012         
Jun 10 20:19:59 s0 StorageManager[3652]: Using the config file found at /etc/columnstore/storagemanager.cnf
 
Jun 10 20:19:59 s0 StorageManager[3652]: max_concurrent_downloads = 20
 
Jun 10 20:19:59 s0 StorageManager[3652]: max_concurrent_downloads = 21
 
Jun 10 20:19:59 s0 StorageManager[3652]: max_concurrent_uploads = 20
 
Jun 10 20:19:59 s0 StorageManager[3652]: max_concurrent_uploads = 21
 
Jun 10 20:19:59 s0 StorageManager[3652]: StorageManager started.
 
Jun 10 20:19:59 s0 StorageManager[3652]: SessionManager waiting for sockets.
 
Jun 10 20:19:59 s0 StorageManager[3649]: StorageManager main process has started
 
Jun 10 20:20:00 s0 workernode[3668]: 00.677516 |0|0|0| I 30 CAL0000: WorkerNode main process has started         
Jun 10 20:20:01 s0 controllernode[3686]: 01.712532 |0|0|0| D 29 CAL0000: DBRM Controller: Connected to DBRM_Worker1         
Jun 10 20:20:02 s0 ExeMgr[3722]: 02.747209 |0|0|0| I 16 CAL0008: No such file or directory 
Jun 10 20:20:02 s0 writeengineserver[3726]: 02.779569 |0|0|0| I 32 CAL0001: WriteEngine main process has started   
Jun 10 20:20:05 s0 DMLProc[3757]: 05.769310 |0|0|0| I 20 CAL0002: DMLProc starts rollbackAll. 
Jun 10 20:20:05 s0 controllernode[3686]: 05.771392 |0|0|0| C 29 CAL0000: InetStreamSocket::readToMagic(): I/O error1: rc-1; poll signal interrupt ( POLLHUP POLLERR )         
Jun 10 20:20:05 s0 ddlpackageproc[3748]: 05.772440 |0|0|0| C 23 CAL0008: DDLProc main process has started 
Jun 10 20:20:05 s0 controllernode[3686]: 05.784473 |0|0|0| C 29 CAL0000: InetStreamSocket::readToMagic(): I/O error1: rc-1; poll signal interrupt ( POLLHUP POLLERR )         
Jun 10 20:20:05 s0 DMLProc[3757]: 05.793885 |0|0|0| I 20 CAL0002: DMLProc will rollback 1 tables. 
Jun 10 20:20:05 s0 DMLProc[3757]: 05.794027 |0|0|0| I 20 CAL0002: DMLProc is rolling back transaction 7 
Jun 10 20:20:05 s0 writeengine[3770]: 05.841310 |0|0|0| I 19 CAL0060: dbbuilder system catalog status: System catalog appears to exist.  It will remain intact for reuse.  The database is not recreated.


Generated at Thu Feb 08 02:55:41 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.