Monday, November 13, 2017

Re: Vim surprisingly slow?

On Mon, Nov 13, 2017 at 09:33:49PM +0100, Christian Brabandt wrote:
>
> On So, 12 Nov 2017, Tim Chase wrote:
>
> > Taking on the challenge listed here
> >
> > https://dev.to/jorinvo/csv-challenge-1al
> >
> > it provides a .json file link to mung into date-named files (never
> > mind that these happen to all be the same date), I came up with this
> > vim solution:
> >
> > :g/.*name":"\([^"]*\)".*card":"\([^"]*\)".*/let
> > s=substitute(getline('.'), '.*stamp":"\(\d\+\)-\(\d\+\)-\(\d\+\).*',
> > '\1\2\3','').'.txt'|s//\1,\2/|exec ".w!>>".s
> >
> > which works. But for some reason, it is *painfully* slow on my
> > machine. The basic intent is that it identifies rows with a (fake)
> > credit-card number, snapshots the YYYYMMMDD.txt filename, then turns
> > the row into a CSV entry ("name, CC"), and writes (appending) that one
> > line into the output filename.
> >
> > The whole thing should happen in a blink. Maybe a second at worst.
> > But this was walk-away-do-something-and-come-back slow.
> >
> > If I change the "exec" to an "echo", it's as fast as I expect.
> >
> > Any idea what might be making the exec so slow?
>
> No idea and I bet running it under gdb will make it even slower :(
>
> Nevertheless can you try this with a debug Vim and hit <Ctrl>-C
>
> This should give us a clue, which codepath is slow. Please try this
> several times, so we are sure, that we hit the slow codepath.
>
> Of course, easier would be to provide a correct profiling information :)

I profiled Vim while running this command, but my gprof-fu isn't strong enough
to see the problem. I tried different combinations of old/new regexp engine,
enabling/disabling autocmds, :silent, but these didn't make a discernible
difference.

The gprof logs can be found at http://unnovative.net/json_challenge/,
if anybody smarter than I cares to take a look.

The odd thing that I noticed is that, according to htop, the Vim process spends
lots of cycles in IOWait.

Here's what iotop shows during a typical run:

Total DISK READ : 0.00 B/s | Total DISK WRITE : 1372.27 K/s
Actual DISK READ: 0.00 B/s | Actual DISK WRITE: 2.68 M/s
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
304 be/3 root 0.00 B/s 0.00 B/s 0.00 % 80.22 % [jbd2/nvme0n1p2-]
17734 be/4 fadein 0.00 B/s 1372.27 K/s 0.00 % 0.89 % vim -c source slow.vim data.json


That's a lot of writing to my hard disk nvme0n1p2. It looks like Vim thrashing
a temp file somewhere, but I didn't see anything that looked likely under
/proc/$(pgrep vim)/fd, and

lsof -p $(pgrep vim)

didn't turn up anything that looked out of the ordinary. Just to be sure I also
tried disabling the swap file

:set noswf

but still, Vim thrashes.

--
Erik Falor
Registered Linux User #445632 http://unnovative.net

--
--
You received this message from the "vim_use" maillist.
Do not top-post! Type your reply below the text you are replying to.
For more information, visit http://www.vim.org/maillist.php

---
You received this message because you are subscribed to the Google Groups "vim_use" group.
To unsubscribe from this group and stop receiving emails from it, send an email to vim_use+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

No comments: