Date: Sat, 07 Oct 2017 00:41:50 +1030 From: Wayne Sierke <ws@au.dyndns.ws> To: Janos Dohanics <web@3dresearch.com>, FreeBSD Questions <freebsd-questions@freebsd.org> Subject: Re: Application startup time Message-ID: <1507299110.2905.8.camel@au.dyndns.ws> In-Reply-To: <20171006083750.2c5331ac8c120ab9624115d4@3dresearch.com> References: <20171005133321.dc9114dee1a31346b96a4d08@3dresearch.com> <1507290916.2905.5.camel@au.dyndns.ws> <20171006083750.2c5331ac8c120ab9624115d4@3dresearch.com>
next in thread | previous in thread | raw e-mail | index | archive | help
On Fri, 2017-10-06 at 08:37 -0400, Janos Dohanics wrote:
> On Fri, 06 Oct 2017 22:25:16 +1030
> Wayne Sierke <ws@au.dyndns.ws> wrote:
>
> > On Thu, 2017-10-05 at 13:33 -0400, Janos Dohanics wrote:
> > > Greetings,
> > >
> > > I have a fairly recently built computer: i7-4790K CPU @ 4.00GHz,
> > > 32GB RAM, GeForce GT 730, FreeBSD 10.4-BETA2.
> > >
> > > On this computer, I have thunderbird-52.3.0_3, installed from
> > > ports.
> > >
> > > Thunderbird takes 38 seconds to start up, that is, from clicking
> > > the
> > > icon until Thunderbird offers a login prompt.
> > > [...]
> >
> > Hi Janos,
> >
> > Best guess is that 38s includes 30s of "network issue" (probably
> > dns)
> > delay time. Given that the Windows TB client doesn't appear to
> > suffer
> > from the same problem - and assuming that it is configured to
> > access
> > the same mail servers - that may help you isolate a network
> > configuration problem. A good place to start would be to compare
> > the
> > DNS configuration in FreeBSD vs the Windows VM.
> >
> > The "freezes" are a bit curious. If they're repeatable (i.e. occur
> > in
> > response to a specific action) you could put TB into "offline" mode
> > and see if the freezes still occur. If they don't then they are
> > probably related to the same network issue.
>
> Hi Wayne,
>
> DNS doesn't seem to be the bottleneck:
>
> $ time drill imap.telissant.net
> ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 49359
> ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0
> ;; QUESTION SECTION:
> ;; imap.telissant.net. IN A
>
> ;; ANSWER SECTION:
> imap.telissant.net. 23887 IN A 104.225.1.170
>
> ;; AUTHORITY SECTION:
>
> ;; ADDITIONAL SECTION:
>
> ;; Query time: 0 msec
> ;; SERVER: 10.61.70.7
> ;; WHEN: Fri Oct 6 08:26:38 2017
> ;; MSG SIZE rcvd: 52
>
> real 0m0.029s
> user 0m0.001s
> sys 0m0.001s
>
> 10.61.70.7 is the FreeBSD computer with the troublesome Thunderbird and
> also is the host for the Win7 virtual machine, which looks up
> 10.61.70.7 for DNS resolution.
>
> However, I ran truss(1) which showed errors like:
>
> 0.054980624 recvmsg(0x4,0x7fffffffdd40,0x0) ERR#35 'Resource temporarily unavailable'
> 0.055094665 recvmsg(0x4,0x7fffffffddd0,0x0) ERR#35 'Resource temporarily unavailable'
> 0.055193841 recvmsg(0x4,0x7fffffffdcc0,0x0) ERR#35 'Resource temporarily unavailable'
> 0.055211203 recvmsg(0x4,0x7fffffffdcc0,0x0) ERR#35 'Resource temporarily unavailable'
> 0.055297486 recvmsg(0x4,0x7fffffffdd60,0x0) ERR#35 'Resource temporarily unavailable'
> 0.055314573 recvmsg(0x4,0x7fffffffdd60,0x0) ERR#35 'Resource temporarily unavailable'
> 0.055435337 recvmsg(0x4,0x7fffffffddf0,0x0) ERR#35 'Resource temporarily unavailable'
> 0.055452586 recvmsg(0x4,0x7fffffffddf0,0x0) ERR#35 'Resource temporarily unavailable'
>
> and many like these:
>
> 0.657764282 _umtx_op(0x8013151a0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x18,0x7fffddfccce8) ERR#60 'Operation timed out'
> 0.672757944 _umtx_op(0x8013152f0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x18,0x7fffdc3bec98) ERR#60 'Operation timed out'
> 0.688696796 _umtx_op(0x8013152f0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x18,0x7fffdc3bec98) ERR#60 'Operation timed out'
> 0.706338501 _umtx_op(0x8013152f0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x18,0x7fffdc3bec98) ERR#60 'Operation timed out'
>
> and
>
> 1.905534690 getpeername(40,0x7fffdfdfc778,0x7fffdfdfc744) ERR#57 'Socket is not connected'
> 1.967428986 getpeername(51,0x7fffdfdfc7a8,0x7fffdfdfc774) ERR#57 'Socket is not connected'
> 1.967580715 getpeername(51,0x7fffdfdfc970,0x7fffdfdfc934) ERR#57 'Socket is not connected'
> 1.997209982 getpeername(51,0x7fffdfdfc970,0x7fffdfdfc934) ERR#57 'Socket is not connected'
>
> and
>
> 6.783927993 _umtx_op(0x8013153e0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call'
> 6.784120019 sigreturn(0x7fffdafb3500) ERR#4 'Interrupted system call'
> 103.644696383 _umtx_op(0x8013153e0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call'
> 103.644887820 sigreturn(0x7fffdafb3f40) ERR#4 'Interrupted system call'
> 108.663319712 _umtx_op(0x8013153e0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call'
> 108.663460460 sigreturn(0x7fffdafb3f40) ERR#4 'Interrupted system call'
> 113.668752752 _umtx_op(0x8013153e0,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) ERR#4 'Interrupted system call'
>
> Perhaps a bug in Thunderbird?
While hardly a thorough comparison I can tell you that I get what
appears to be a strikingly similar set of messages from truss with my
Thunderbird. Un(?)fortunately I would say those messages are probably
not significant.
Below are some events whose timing in particular might make for an
interesting comparison.
First dns server connection:
0.194129868 open("/etc/resolv.conf",O_CLOEXEC,0666) = 13 (0xd)
0.194383797 open("/etc/nsswitch.conf",O_CLOEXEC,0666) = 13 (0xd)
0.196764530 open("/etc/hosts",O_CLOEXEC,0666) = 13 (0xd)
0.197027552 connect(14,{ AF_INET 172.17.17.42:53 },16) = 0 (0x0)
0.197582820 recvfrom(14,"\f\M-:\M^E\M^@\0\^A\0\^A\0\^A\0"...,65536,0x0,{ AF_INET 172.17.17.42:53 },0x7fffffffb8dc) = 93 (0x5d)
0.320484741 connect(16,{ AF_INET 172.17.17.42:53 },16) = 0 (0x0)
0.321022309 recvfrom(16,"|\^]\M^E\M^@\0\^A\0\^A\0\^A\0\^A"...,65536,0x0,{ AF_INET 172.17.17.42:53 },0x7fffffffb86c) = 93 (0x5d)
First imap server connection and send/recv:
3.613094209 connect(46,{ AF_INET 172.17.17.142:993 },16) ERR#36 'Operation now in progress'
3.613132454 getpeername(46,0x7fffdf9fa970,0x7fffdf9fa934) ERR#57 'Socket is not connected'
3.614344524 sendto(46,"\^V\^C\^A\0\M^Q\^A\0\0\M^M\^C\^C"...,150,0x0,NULL,0x0) = 150 (0x96)
3.614382113 recvfrom(46,0x825157a80,5,0x0,0x0,0x0) ERR#35 'Resource temporarily unavailable'
3.687505051 recvfrom(46,"\^V\^C\^A\0005",5,0x0,NULL,0x0) = 5 (0x5)
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?1507299110.2905.8.camel>