Measure max wakeup time

Author: knizhnik

multimaster.c

@@ -518,13 +518,11 @@ MtmAdjustOldestXid(TransactionId xid)
 				}
 			}
         } 
-		if (MtmUseDtm) { 
-			if (prev != NULL) { 
-				Mtm->transListHead = prev;
-				Mtm->oldestXid = xid = prev->xid;            
-			} else if (TransactionIdPrecedes(Mtm->oldestXid, xid)) { 
-				xid = Mtm->oldestXid;
-			}
+		if (prev != NULL) { 
+			Mtm->transListHead = prev;
+			Mtm->oldestXid = xid = prev->xid;            
+		} else if (TransactionIdPrecedes(Mtm->oldestXid, xid)) { 
+			xid = Mtm->oldestXid;
 		}
 		MtmUnlock();
     }
@@ -782,13 +780,19 @@ MtmPostPrepareTransaction(MtmCurrentTrans* x)
 		MtmUnlock();
 		MtmResetTransaction(x);
 	} else { 
+		time_t wakeupTime;
+		static time_t maxWakeupTime;
 		/* wait votes from all nodes */
 		while (!ts->votingCompleted) { 
 			MtmUnlock();
 			WaitLatch(&MyProc->procLatch, WL_LATCH_SET, -1);
 			ResetLatch(&MyProc->procLatch);			
 			MtmLock(LW_SHARED);
 		}
+		wakeupTime = MtmGetCurrentTime() - ts->wakeupTime;
+		if (wakeupTime > maxWakeupTime) { 
+			maxWakeupTime = wakeupTime;
+		}
 		x->status = ts->status;
 		MTM_LOG3("%d: Result of vote: %d", MyProcPid, ts->status);
 		MtmUnlock();
@@ -979,6 +983,7 @@ void MtmWakeUpBackend(MtmTransState* ts)
 {
 	MTM_LOG3("Wakeup backed procno=%d, pid=%d", ts->procno, ProcGlobal->allProcs[ts->procno].pid);
 	ts->votingCompleted = true;
+	ts->wakeupTime = MtmGetCurrentTime();
 	SetLatch(&ProcGlobal->allProcs[ts->procno].procLatch); 
 }
 

multimaster.h

@@ -135,6 +135,7 @@ typedef struct MtmTransState
 	int            procno;             /* pgprocno of transaction coordinator waiting for responses from replicas, 
 							              used to notify coordinator by arbiter */
 	int            nSubxids;           /* Number of subtransanctions */
+	time_t         wakeupTime;         
 	MtmMessageCode cmd;                /* Notification message to be sent */
   	struct MtmTransState* nextVoting;  /* Next element in L1-list of voting transactions. */
     struct MtmTransState* next;        /* Next element in L1 list of all finished transaction present in xid2state hash */

tests/deploy_layouts/cluster.yml

@@ -46,15 +46,15 @@
     - "wal_sender_timeout = 0"
     - "max_replication_slots = 10"
     - "max_connections = 200"
-    - "max_worker_processes = 200"
+    - "max_worker_processes = 100"
     - "shared_preload_libraries = 'raftable,multimaster'"
     - "multimaster.conn_strings = '{{connections}}'"
     - "multimaster.node_id = {{ node_id }}"
     - "multimaster.buffer_size = 65536"
     - "multimaster.queue_size = 1073741824"
     - "multimaster.arbiter_port = 5600"
     - "multimaster.vacuum_delay = 1"
-    - "multimaster.workers = 100"
+    - "multimaster.workers = 32"
     - "multimaster.use_dtm = 0"
 
   - name: restart postgrespro

tests/perf.results

@@ -192,3 +192,63 @@ Bench finished at Чт. апр. 14 15:57:08 MSK 2016
 Bench started at Чт. апр. 14 16:07:25 MSK 2016
 
 Bench finished at Чт. апр. 14 16:58:03 MSK 2016
+Bench started at Чт. апр. 14 17:14:41 MSK 2016
+astro5:{tps:841.620253, transactions:1000000, selects:0, updates:2000610, aborts:1045, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:10000, hosts:3}
+Bench finished at Чт. апр. 14 17:34:30 MSK 2016
+Bench started at Чт. апр. 14 17:38:52 MSK 2016
+astro5:{tps:103207.588648, transactions:100000, selects:200000, updates:0, aborts:0, abort_percent: 0, readers:0, writers:100, update_percent:0, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 17:38:53 MSK 2016
+Bench started at Чт. апр. 14 17:39:15 MSK 2016
+astro5:{tps:600.228131, transactions:100000, selects:0, updates:200058, aborts:94, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 17:42:02 MSK 2016
+Bench started at Чт. апр. 14 17:47:53 MSK 2016
+astro5:{tps:2826.840100, transactions:100000, selects:0, updates:200060, aborts:105, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 17:48:28 MSK 2016
+Bench started at Чт. апр. 14 17:50:15 MSK 2016
+astro5:{tps:1203.074674, transactions:100000, selects:0, updates:200038, aborts:102, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 17:51:39 MSK 2016
+Bench started at Чт. апр. 14 17:56:22 MSK 2016
+astro5:{tps:16673.903141, transactions:100000, selects:0, updates:200044, aborts:68, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 17:56:29 MSK 2016
+Bench started at Чт. апр. 14 18:01:48 MSK 2016
+astro5:{tps:15729.463298, transactions:100000, selects:0, updates:200052, aborts:68, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:01:55 MSK 2016
+Bench started at Чт. апр. 14 18:33:55 MSK 2016
+astro5:{tps:16955.322556, transactions:100000, selects:0, updates:200074, aborts:83, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:34:01 MSK 2016
+Bench started at Чт. апр. 14 18:34:29 MSK 2016
+astro5:{tps:16920.929961, transactions:150000, selects:0, updates:300194, aborts:187, abort_percent: 0, readers:0, writers:150, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:34:39 MSK 2016
+Bench started at Чт. апр. 14 18:35:08 MSK 2016
+
+Bench finished at Чт. апр. 14 18:35:09 MSK 2016
+Bench started at Чт. апр. 14 18:35:40 MSK 2016
+
+Bench finished at Чт. апр. 14 18:35:40 MSK 2016
+Bench started at Чт. апр. 14 18:36:33 MSK 2016
+
+Bench finished at Чт. апр. 14 18:36:34 MSK 2016
+Bench started at Чт. апр. 14 18:38:59 MSK 2016
+astro5:{tps:15017.551012, transactions:150000, selects:0, updates:300180, aborts:200, abort_percent: 0, readers:0, writers:150, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:39:09 MSK 2016
+Bench started at Чт. апр. 14 18:42:34 MSK 2016
+astro5:{tps:6604.488490, transactions:150000, selects:0, updates:300154, aborts:215, abort_percent: 0, readers:0, writers:150, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:42:57 MSK 2016
+Bench started at Чт. апр. 14 18:45:11 MSK 2016
+astro5:{tps:734.388293, transactions:100000, selects:0, updates:200058, aborts:102, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:47:28 MSK 2016
+Bench started at Чт. апр. 14 18:48:27 MSK 2016
+astro5:{tps:2989.544487, transactions:100000, selects:0, updates:200060, aborts:99, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:49:01 MSK 2016
+Bench started at Чт. апр. 14 18:49:34 MSK 2016
+astro5:{tps:2579.759122, transactions:100000, selects:0, updates:200066, aborts:99, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:50:14 MSK 2016
+Bench started at Чт. апр. 14 18:50:33 MSK 2016
+astro5:{tps:1825.359630, transactions:100000, selects:0, updates:200080, aborts:117, abort_percent: 0, readers:0, writers:100, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:51:28 MSK 2016
+Bench started at Чт. апр. 14 18:51:58 MSK 2016
+astro5:{tps:1769.625629, transactions:150000, selects:0, updates:300148, aborts:230, abort_percent: 0, readers:0, writers:150, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 18:53:23 MSK 2016
+Bench started at Чт. апр. 14 18:53:42 MSK 2016
+astro5:{tps:180.239135, transactions:150000, selects:0, updates:300156, aborts:232, abort_percent: 0, readers:0, writers:150, update_percent:100, accounts:500000, iterations:1000, hosts:3}
+Bench finished at Чт. апр. 14 19:07:34 MSK 2016

tests/perf.yml

@@ -46,7 +46,7 @@
   - name: run transfers
     shell: >
       ~/pg_cluster/install/bin/dtmbench {{connections}}
-      -w {{ nconns }} -r 0 -n 10000 -a 500000 -p {{ up }} |
+      -w {{ nconns }} -r 0 -n 1000 -a 500000 -p {{ up }} |
       tee -a perf.results |
       sed "s/^/`hostname`:/"
     register: transfers_result