Re: [9fans] cpu command latency

[arisawa <arisawa@ar.aichi-u.ac.jp>]

Hello

this is a partial report of cpu command latency.

we have code below in rexcall() of cpu.c 

	na = netmkaddr(host, 0, service);
	//na = netmkaddr(host, “tcp”, service);//DBG
	syslog(0,"cpu","rexcall:netmkaddr %lld μsec; %s",(nsec()-t0)/1000,na);//DBG
	procsetname("dialing %s", na);
	syslog(0,"cpu","rexcall:dialing %lld μsec; %s",(nsec()-t0)/1000,na);//DBG
	if((*fd = dial(na, 0, devdir, 0)) < 0)
		return "can't dial";
	syslog(0,"cpu","rexcall:dial %lld μsec",(nsec()-t0)/1000);//DBG

lines with “DBG” are code added for measurement.
looking the result I found dial() takes as much as on second in my home network!

	vbt May 14 21:27:52 rexcall:netmkaddr 122 μsec; net!io!ncpu
	vbt May 14 21:27:52 rexcall:dialing 592 μsec; net!io!ncpu
	vbt May 14 21:27:53 rexcall:dial 1161556 μsec

	vbt May 14 21:27:57 rexcall:netmkaddr 677 μsec; net!io!ncpu
	vbt May 14 21:27:57 rexcall:dialing 1082 μsec; net!io!ncpu
	vbt May 14 21:27:58 rexcall:dial 1109949 μsec

replacing
	na = netmkaddr(host, 0, service);
by
	na = netmkaddr(host, “tcp”, service);
we get much better performance as shown below.
	vbt May 14 22:21:18 rexcall:netmkaddr 489 μsec; tcp!io!ncpu
	vbt May 14 22:21:18 rexcall:dialing 861 μsec; tcp!io!ncpu
	vbt May 14 22:21:18 rexcall:dial 3099 μsec

	vbt May 14 22:21:22 rexcall:netmkaddr 565 μsec; tcp!io!ncpu
	vbt May 14 22:21:22 rexcall:dialing 977 μsec; tcp!io!ncpu
	vbt May 14 22:21:22 rexcall:dial 7287 μsec

isn’t it better the default net be “tcp”?
even if you do want “net”, you can do
	cpu -h net!host 

Kenji Arisawa



> 2016/05/13 0:40、Skip Tavakkolian <skip.tavakkolian@gmail.com> のメール：
> 
> it might be worth instrumenting the cpu command to time the authenticaiton step. i think that's where the problem is.
> 
> On Wed, May 11, 2016 at 3:39 PM Skip Tavakkolian <skip.tavakkolian@gmail.com> wrote:
> what's the latency caused by the auth step?
> FYI, from Seattle I see about 8 seconds to establish but as Charles noted, it's reasonably fast after that.
> 
> 
> On Wed, May 11, 2016 at 2:05 PM arisawa <arisawa@ar.aichi-u.ac.jp> wrote:
> Hello,
> 
> we can measure the latency that comes from network connection
> by executing simple program such as telnet or something others
> to the port 8006 of grid.nyx.link. the content is:
> #!/bin/rc
> cat $net/local
> cat $net/remote
> 
> yes the DNS may make a problem in IPv4/IPv6 mixed environment.
> my server supports both IPs.
> the cpu command will select IPv4. the command does not have “-6” option.
> If we want to connect by IPv6, literal IP address is required in the argument of the command.
> 
> Kenji Arisawa
> 
> > In my experience, it's almost unfailingly the DNS that slows down
> > establishing an Internet session of any type.
> >
> > Lucio.
> 
> > 2016/05/12 0:23、Kenny Lasse Hoff Levinsen <kennylevinsen@gmail.com> のメール：
> >
> > Well, based on the 9fs test that was posted, I'd think dial is being awfully slow.
> >
> > Maybe try something simpler? aux/listen1 echo hello and a simple network connection?
> >
> > Best regards,
> > Kenny Levinsen
> >
> > On 11. maj 2016, at 16.13, Charles Forsyth <charles.forsyth@gmail.com> wrote:
> >
> >>
> >> On 11 May 2016 at 14:44, Kenny Lasse Hoff Levinsen <kennylevinsen@gmail.com> wrote:
> >> Delete the channel from /srv in the loop to test a full remote mount dance, including the initial dial. It shouldn't take 3s to dial, though.
> >>
> >> There's something initially slow in connecting to  grid.nyx.link with cpu, and setting up, but once there it's fine.
> 
>