El día jueves, enero 02, 2020 a las 12:58:21p. m. +0000, Chris Green escribió:
> Well I've started trying to diagnose this, I'm less sure now that it
> only happens across the ssh connection, that may be a red herring.
> I've changed the main disk drive on my dekstop system (where mutt
> runs) from a 1TB spinning hard disk to a 1TB SSD and I *think* the
> slowness may be related to this.
>
> With the SSD some things are *much* faster, e.g. loading a 5000
> message mbox (my 'sent' mailbox) is almost instant now whereas it used
> to take several seconds. So the SSD is faster in general, a *lot*
> faster.
>
> I have the recommended trace running and the only significant delays I
> can see are:-
>
> ...
> ...
> ...
> 12:40:19.110589 write(1, "\r\33[J\33[H\33[30m\33[46m---Mutt: ~/Mail"...,
> 3622) = 3622
> 12:40:19.110737 rt_sigaction(SIGINT, {sa_handler=0x55bca4ac2440,
> sa_mask=[], sa_flags=SA_RESTORER, sa_restor er=0x7f00502f1470}, NULL, 8) = 0
> 12:40:19.110791 write(1, "\33[?1h\33=", 7) = 7
> 12:40:19.110826 poll([{fd=0, events=POLLIN}], 1, 15000) = 1 ([{fd=0,
> revents=POLLIN}])
> 12:40:25.110942 read(0, "c", 1) = 1
> 12:40:25.111099 rt_sigaction(SIGINT, {sa_handler=0x55bca4ac2440,
> sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART , sa_restorer=0x7f00502f1470},
> NULL, 8) = 0
> 12:40:25.111211 write(1, "\33[?12l\33[?25h", 12) = 12
> 12:40:25.111433 stat("/home/chris/Mail/In/inbox", {st_mode=S_IFREG|0600,
> st_size=3065472, ...}) = 0
> 12:40:25.111575 stat("/var/mail/chris", {st_mode=S_IFREG|0600,
> st_size=726, ...}) = 0
> 12:40:25.111649 stat("/home/chris/Mail/In/inbox", {st_mode=S_IFREG|0600,
> st_size=3065472, ...}) = 0
> 12:40:25.111712 stat("/home/chris/Mail/Li/alug", {st_mode=S_IFREG|0600,
> st_size=298691, ...}) = 0
> ...
> ...
> ...
> 12:40:25.115157 stat("/home/chris/Mail/In/odin", {st_mode=S_IFREG|0600,
> st_size=1083391, ...}) = 0
> 12:40:25.115348 write(1, "\r\33[60dOpen mailbox ('?' for list"..., 55) =
> 55
> 12:40:25.115450 rt_sigaction(SIGINT, {sa_handler=0x55bca4ac2440,
> sa_mask=[], sa_flags=SA_RESTORER, sa_restor er=0x7f00502f1470}, NULL, 8) = 0
> 12:40:25.115552 read(0, "\r", 1) = 1
> 12:40:27.765854 rt_sigaction(SIGINT, {sa_handler=0x55bca4ac2440,
> sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART , sa_restorer=0x7f00502f1470},
> NULL, 8) = 0
> 12:40:27.766147 write(1, "\33[60;13H: \33[K\33(B\33[m", 19) = 19
> 12:40:27.766445 write(1, "~/Mail/Li/x2go\33(B\33[m", 20) = 20
> 12:40:27.766650 stat("/home/chris/Mail/Li/x2go", {st_mode=S_IFREG|0600,
> st_size=264290, ...}) = 0
> ...
> ...
> ...
> 12:40:27.766999 utime("/home/chris/Mail/Li/x2go", {actime=1577968429 /*
> 2020-01-02T12:33:49+0000 */, modtime =1577968434 /* 2020-01-02T12:33:54+0000
> */}) = 0
> 12:40:27.767127 write(1, "\r\33[32mMailbox is unchanged.\33[39m"..., 41)
> = 41
> 12:40:27.767183 stat("/home/chris/Mail/In/inbox", {st_mode=S_IFREG|0600,
> st_size=3065472, ...}) = 0
> 12:40:27.767243 utime("/home/chris/Mail/In/inbox", {actime=1577968819 /*
> 2020-01-02T12:40:19+0000 */, modtim e=1577966702 /* 2020-01-02T12:05:02+0000
> */}) = 0
> 12:40:27.767325 close(3) = 0
> 12:40:27.767468 nanosleep({tv_sec=1, tv_nsec=0}, 0x7fff86fc8060) = 0
> 12:40:28.767837 lstat("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...})
> = 0
> 12:40:28.768113 lstat("/home/chris", {st_mode=S_IFDIR|0755, st_size=4096,
> ...}) = 0
> ...
> ...
> ...
>
> I *think* the one that is the delay I'm seeing is that two and a half
> second delay after read(0, "\r", 1). I guess the long delays after
> poll(...) are what one would expect as it's mutt waiting for me to do
> something, and the one second delay at nanosleep() is as coded.
>
> So, what's that read() doing that takes so long?
In the lines:
12:40:25.115552 read(0, "\r", 1) = 1
12:40:27.765854 rt_sigaction(SIGINT, {sa_handler=0x55bca4ac2440, sa_mask=[],
sa_flags=SA_RESTORER|SA_RESTART , sa_restorer=0x7f00502f1470}, NULL, 8) = 0
12:40:27.766147 write(1, "\33[60;13H: \33[K\33(B\33[m", 19) = 19
the time 12:40:25.115552 is when the read(2) sys call on STDIN started
and the next time 12:40:27.765854 when the input was available.
matthias
--
Matthias Apitz, ✉ g...@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub
"Glaube wenig, hinterfrage alles, denke selbst: Wie man Manipulationen
durchschaut"
"Believe little, scrutinise all, think by your own: How see through
manipulations"
ISBN-10: 386489218X
