fix refreshes database trait (WIP)

[ostark]

I was able to reproduce the implicit commit. My idea was to simply use another MySQL connection to perform the ALTER TABLE.

No luck so far.

[ostark]

The new connection hangs:

SHOW ENGINE INNODB STATUS;

=====================================
2022-09-28 16:54:24 0x309846000 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 48 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 6453 srv_active, 0 srv_shutdown, 373838 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 15219
OS WAIT ARRAY INFO: signal count 14517
RW-shared spins 2489, rounds 3075, OS waits 671
RW-excl spins 7883, rounds 146905, OS waits 2797
RW-sx spins 12, rounds 295, OS waits 6
Spin rounds per wait: 1.24 RW-shared, 18.64 RW-excl, 24.58 RW-sx
------------------------
LATEST FOREIGN KEY ERROR
------------------------
2022-09-28 16:13:35 0x309640000 Transaction:
TRANSACTION 587832, ACTIVE 30 sec inserting
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 9243, OS thread handle 13042450432, query id 479544 localhost 127.0.0.1 root update
INSERT INTO `craft_content` (`elementId`, `siteId`, `title`, `dateCreated`, `dateUpdated`, `uid`) VALUES (678, 1, 'Odio quas eos dicta voluptatibus corrupti.', '2022-09-28 14:13:05', '2022-09-28 14:13:05', '10430439-f9a9-4dc8-bbfc-9ce86a5aafa4')
Foreign key constraint fails for table `pest`.`craft_content`:
,
  CONSTRAINT `craft_fk_fadeqpgajlldbkhlakaicusetrfbcdrhpqqt` FOREIGN KEY (`elementId`) REFERENCES `craft_elements` (`id`) ON DELETE CASCADE
Trying to add in child table, in index craft_idx_wfsonlkheigvotbasjxgrawsxxqnabhogufw tuple:
DATA TUPLE: 3 fields;
 0: len 4; hex 800002a6; asc     ;;
 1: len 4; hex 80000001; asc     ;;
 2: len 4; hex 800002a6; asc     ;;

But in parent table `pest`.`craft_elements`, in index PRIMARY,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 15; compact format; info bits 0
 0: len 4; hex 8000029b; asc     ;;
 1: len 6; hex 00000008f7be; asc       ;;
 2: len 7; hex 82000000c7038d; asc        ;;
 3: len 4; hex 8000029a; asc     ;;
 4: SQL NULL;
 5: len 4; hex 8000012f; asc    /;;
 6: len 4; hex 8000005c; asc    \;;
 7: len 20; hex 63726166745c656c656d656e74735c456e747279; asc craft\elements\Entry;;
 8: len 1; hex 81; asc  ;;
 9: len 1; hex 80; asc  ;;
 10: len 5; hex 99adf8e31f; asc      ;;
 11: len 5; hex 99adf8e31f; asc      ;;
 12: SQL NULL;
 13: SQL NULL;
 14: len 30; hex 64613032613635652d333265612d343930642d626631632d626161396261; asc da02a65e-32ea-490d-bf1c-baa9ba; (total 36 bytes);

------------
TRANSACTIONS
------------
Trx id counter 589506
Purge done for trx's n:o < 589503 undo n:o < 0 state: running but idle
History list length 45
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421872238309728, not started
mysql tables in use 1, locked 1
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238308048, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238307208, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238306368, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238305528, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238304688, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238303848, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238303008, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238302168, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238301328, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238300488, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238299648, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421872238298808, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 589501, ACTIVE 20 sec
18 lock struct(s), heap size 1136, 20 row lock(s), undo log entries 57
MySQL thread id 9307, OS thread handle 13040025600, query id 500922 localhost 127.0.0.1 root
Trx read view will not see trx with id >= 589501, sees < 589501
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
 ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 1
2662 OS file reads, 318908 OS file writes, 229052 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 19.73 writes/s, 15.19 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 13 merges
merged operations:
 insert 9, delete mark 4, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 34679, node heap has 43 buffer(s)
Hash table size 34679, node heap has 25 buffer(s)
Hash table size 34679, node heap has 8 buffer(s)
Hash table size 34679, node heap has 65 buffer(s)
Hash table size 34679, node heap has 30 buffer(s)
Hash table size 34679, node heap has 14 buffer(s)
Hash table size 34679, node heap has 10 buffer(s)
Hash table size 34679, node heap has 15 buffer(s)
563.22 hash searches/s, 223.16 non-hash searches/s
---
LOG
---
Log sequence number          1280502654
Log buffer assigned up to    1280502654
Log buffer completed up to   1280502654
Log written up to            1280502654
Log flushed up to            1280502654
Added dirty pages up to      1280502654
Pages flushed up to          1280502654
Last checkpoint at           1280502654
140712 log i/o's done, 12.19 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 136970240
Dictionary memory allocated 3801856
Buffer pool size   8191
Free buffers       1560
Database pages     6421
Old database pages 2350
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 6955, not young 47108
0.00 youngs/s, 0.00 non-youngs/s
Pages read 2363, created 8083, written 134002
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 6421, unzip_LRU len: 0
I/O sum[294]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Process ID=2565, Main thread ID=0x308cbf000 , state=sleeping
Number of rows inserted 207452, updated 9473, deleted 20122, read 15709571
15.25 inserts/s, 0.31 updates/s, 0.10 deletes/s, 64.06 reads/s
Number of system rows inserted 42623, updated 115156, deleted 38903, read 16019462
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 544.09 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

[ostark]

SET foreign_key_checks = 0 does not help

[ostark]

Arrggh, I'm considering to implement a manual rollback. It should be that hard to record all inserts 🤔

[ostark]

@markhuot please have a look

[markhuot]

Oh. my. god. That's amazing. I never thought of that. Checking this out now!

[markhuot]

Oh, and yea… that hanging new connection is the same issue I keep running in to. I've wanted to have multiple \Craft::$app instances floating around so each get('/foo') request could hit a new app and replicate the stateless approach you get with PHP/Nginx, but it's the same thing, as soon as you run a second test the DB connection hangs for ever and ever. I've never figured out what's causing the hang, it feels like table locks but I can't reason as to what/why is causing that.

[ostark]

Yeah. It was fun and pain at the same time.

---

I tried to fix the skipped Matrix test, but gave up eventually.

[markhuot]

I had another thought here: in React you have to put all your hooks at the top of your component so while React is rendering it can be be sure your user land code won’t introduce any side-effects to the rendering process.

What if we took a similar approach: all field modifications have to go first. Then, we only have to track Field modifications for manual rollback. Once the field modifications are done we can restart the refreshesDatabase transaction for the entities and let it work like normal. At the end we manually roll back the fields and your state is reset.

As a convenience, we can throw an exception if you try to modify a field after interacting with an entry factory, for example.

[markhuot]

Okay, I played with requiring fields factories to come first and I quite like it. I have a PR for it here, that I'm waiting for tests to complete on and then I'll get merged: https://github.com/markhuot/craft-pest/pull/17

[ostark]

OK