Re: 6.4-release tset(1) really slow, what have I missed?

On Sun, Dec 2, 2018 at 2:15 PM Adam Thompson <athompso@athompso.net> wrote:

> I've successfully installed OpenBSD 6.4-RELEASE at OVH, but I'm noticing
> one thing there that's different from everywhere else I've used 6.4.
>
> tset(1) takes approximately 12-15 seconds to execute, (almost) every
> time.
>
> On a DigitalOcean VPS running 6.3-STABLE (via openup) tset sensibly
> takes about 1 or 2 seconds:
> athompso@mail.athompso.net:~$ time tset -s
> TERM=xterm;
> 0m01.01s real 0m00.00s user 0m00.01s system
> athompso@mail.athompso.net:~$ uname -r
> 6.3
>
> On the OVH VPS running 6.4-STABLE (via openup), the same command takes
> 15 seconds:
> athompso@mail2.athompso.net:~$ time tset -s
> TERM=xterm;
> 0m15.19s real 0m00.00s user 0m00.01s system
> athompso@mail2.athompso.net:~$ uname -r
> 6.4
>
>
> That's from two SSH sessions from the same client with the same
> parameters.
>
> I've captured ktrace(1) output, which shows tset(1) doing, well,
> nothing:
> ...
> 57429/443422 tset 0.035908 CALL
> kbind(0x7f7fffff7678,24,0xecf2201fc1aab9ca)
> 57429/443422 tset 0.035933 RET kbind 0
> 57429/443422 tset 0.035950 CALL
> nanosleep(0x7f7fffff7760,0x7f7fffff7750)
> 57429/443422 tset 0.035967 STRU struct timespec { 1 }
> 57429/443422 tset 15.809238 STRU struct timespec { 0 }
> 57429/443422 tset 15.809272 RET nanosleep 0
> 57429/443422 tset 15.809303 CALL
> kbind(0x7f7fffff76c8,24,0xecf2201fc1aab9ca)
> 57429/443422 tset 15.809380 RET kbind 0
> ...
>
> I don't think this is a bug in 6.4, it's clearly environment-specific...
> but I have no idea what on earth could be causing it.
>

It requested a sleep of 1 second and 15 seconds passed. That's a kernel
timetracking issue, so the output of "sysctl kern.timecounter" would be a
good place to start. Is this is an MP kernel using the CPU TSC, but on a
VM where the virtual CPU's TSCs aren't in sync?


Philip Guenther