From 814d330b8a0e90d187c0bf5fe5ce3a600f5fba0d Mon Sep 17 00:00:00 2001
From: Mark Nadal <mark@gun.eco>
Date: Fri, 20 Sep 2019 00:55:09 -0700
Subject: [PATCH] more logs

---
 gun.js        | 12 ++++++++++++
 lib/radisk.js | 13 ++++++++++++-
 lib/store.js  |  1 +
 3 files changed, 25 insertions(+), 1 deletion(-)

diff --git a/gun.js b/gun.js
index 554eb197..0fe78cf8 100644
--- a/gun.js
+++ b/gun.js
@@ -811,16 +811,20 @@
 					// Maybe... in case the in-memory key we have is a local write
 					// we still need to trigger a pull/merge from peers.
 				} else {
+					var S = +new Date;
 					node = Gun.obj.copy(node);
+					console.log(+new Date - S, 'copy node');
 				}
 				node = Gun.graph.node(node);
 				tmp = (at||empty).ack;
+				var S = +new Date;
 				root.on('in', {
 					'@': msg['#'],
 					how: 'mem',
 					put: node,
 					$: gun
 				});
+				console.log(+new Date - S, 'root got send');
 				//if(0 < tmp){ return }
 				root.on('get', msg);
 			}
@@ -2023,6 +2027,7 @@
 					if(this.to){ this.to.next(msg) } // compatible with middleware adapters.
 					if(!msg){ return false }
 					var id, hash, tmp, raw;
+					var S = +new Date;
 					var meta = msg._||(msg._=function(){});
 					if(!(id = msg['#'])){ id = msg['#'] = Type.text.random(9) }
 					if(!(hash = msg['##']) && u !== msg.put){ hash = msg['##'] = Type.obj.hash(msg.put) }
@@ -2036,12 +2041,15 @@
 							}
 						}
 					}
+					console.log(+new Date - S, 'mesh say prep');
 					dup.track(id).it = msg; // track for 9 seconds, default. Earth<->Mars would need more!
 					if(!peer){ peer = (tmp = dup.s[msg['@']]) && (tmp = tmp.it) && (tmp = tmp._) && (tmp = tmp.via) }
 					if(!peer && mesh.way){ return mesh.way(msg) }
 					if(!peer || !peer.id){ message = msg;
 						if(!Type.obj.is(peer || opt.peers)){ return false }
+						var S = +new Date;
 						Type.obj.map(peer || opt.peers, each); // in case peer is a peer list.
+						console.log(+new Date - S, 'mesh say loop');
 						return;
 					}
 					if(!peer.wire && mesh.wire){ mesh.wire(peer) }
@@ -2065,8 +2073,10 @@
 					peer.batch = peer.tail = null;
 					if(!tmp){ return }
 					if(!tmp.length){ return } // if(3 > tmp.length){ return } // TODO: ^
+					var S = +new Date;
 					try{tmp = (1 === tmp.length? tmp[0] : JSON.stringify(tmp));
 					}catch(e){return opt.log('DAM JSON stringify error', e)}
+					console.log(+new Date - S, 'mesh flush', tmp.length);
 					if(!tmp){ return }
 					send(tmp, peer);
 				}
@@ -2076,12 +2086,14 @@
 			// for now - find better place later.
 			function send(raw, peer){ try{
 				var wire = peer.wire;
+				var S = +new Date;
 				if(peer.say){
 					peer.say(raw);
 				} else
 				if(wire.send){
 					wire.send(raw);
 				}
+				console.log(+new Date - S, 'wire send', raw.length);
 				mesh.say.d += raw.length||0; ++mesh.say.c; // STATS!
 			}catch(e){
 				(peer.queue = peer.queue || []).push(raw);
diff --git a/lib/radisk.js b/lib/radisk.js
index 1f2ba3ac..9eba437f 100644
--- a/lib/radisk.js
+++ b/lib/radisk.js
@@ -44,9 +44,14 @@
 			if(val instanceof Function){
 				var o = cb || {};
 				cb = val;
+				var S; LOG && (S = +new Date);
 				val = r.batch(key);
+				LOG && console.log(+new Date - S, 'rad mem');
 				if(u !== val){
-					cb(u, r.range(val, o), o);
+					LOG && (S = +new Date);
+					var v = r.range(val, o);
+					LOG && console.log(+new Date - S, 'rad range');
+					cb(u, v, o);
 					if(atomic(val)){ return }
 					// if a node is requested and some of it is cached... the other parts might not be.
 				}
@@ -230,7 +235,9 @@
 			r.read = function(key, cb, o){
 				o = o || {};
 				if(RAD && !o.next){ // cache
+					var S; LOG && (S = +new Date);
 					var val = RAD(key);
+					LOG && console.log(+new Date - S, 'rad cached');
 					//if(u !== val){
 						//cb(u, val, o);
 						if(atomic(val)){ cb(u, val, o); return }
@@ -243,6 +250,7 @@
 					file = (u === file)? u : decodeURIComponent(file);
 					tmp = o.next || key || (o.reverse? o.end || '\uffff' : o.start || '');
 					if(!file || (o.reverse? file < tmp : file > tmp)){
+						LOG && console.log(+new Date - S, 'rad read lex'); S = +new Date;
 						if(o.next || o.reverse){ g.file = file }
 						if(tmp = Q[g.file]){
 							tmp.push({key: key, ack: cb, file: g.file, opt: o});
@@ -263,7 +271,9 @@
 					g.info = info;
 					if(disk){ RAD = g.disk = disk }
 					disk = Q[g.file]; delete Q[g.file];
+					LOG && console.log(+new Date - S, 'rad read it in, now ack to:', disk.length); S = +new Date;
 					map(disk, g.ack);
+					console.log(+new Date - S, 'rad read acked');
 				}
 				g.ack = function(as){
 					if(!as.ack){ return }
@@ -282,6 +292,7 @@
 					r.read(tmp, as.ack, o);
 				}
 				if(o.reverse){ g.lex.reverse = true }
+				LOG && (S = +new Date);
 				r.list(g.lex);
 			}
 			function rev(a,b){ return b }
diff --git a/lib/store.js b/lib/store.js
index 124f0eb5..0d0cdaf2 100644
--- a/lib/store.js
+++ b/lib/store.js
@@ -90,6 +90,7 @@ Gun.on('create', function(root){
             root.on('in', {'@': id, put: graph, err: err? err : u, rad: Radix});
             console.log(+new Date - S, 'got sent');
         }, o);
+        console.log(+new Date - S, 'get call');
         function each(val, has, a,b){
             if(!val){ return }
             has = (key+has).split(esc);