view tests/test-progress.t @ 38956:a3cabe9415e1

dirstate: use visitchildrenset in traverse

This speeds up `hg status` a fair amount when there is a very large directory
and narrow is in use.

Timing numbers according to command:

    hyperfine --warmup 1 'hg status'

HGRCPATH points to a file with the following contents:

    [extensions]
    narrow =

mozilla-unified (called m-u below) was at revision #468856.
        regular hash: eb39298e432d
  treemanifests hash: 0553b7f29eaf

large-dir-repo (called l-d-r below) was generated with the following script:

    #!/bin/bash
    hg init large-dir-repo
    mkdir -p large-dir-repo/third_party/rust/log
    touch large-dir-repo/third_party/rust/log/foo.txt
    for i in $(seq 1 30000); do
        d=$(mktemp -d large-dir-repo/third_party/XXXXXXXXX)
        touch $d/file.txt
    done
    hg -R large-dir-repo ci -Am 'rev0' --user test --date '0 0'

for repos that use narrow, the narrowspec was this:

    [includes]
    rootfilesin:third_party/rust/log
    [excludes]

This narrowspec was chosen due to the size of the third_party/rust directory;
this directory was *not* modified in revision #468856 in mozilla-unified.

Importantly, when using narrow, these repos had everything checked out (in the
case of large-dir-repo, that means all 30,001 directories), *before* adding the
narrowspec. This is to simulate the behavior when using a virtual filesystem
that shows everything for the user even if they haven't added it to the
narrowspec yet. This is not a supported configuration, and `hg update` will not
really do the "correct" thing, but non-mutating commands should behave
correctly.

There are two repos below that do not follow the setup above, 'citc1' and
'citc2', which are using a virtual filesystem and can not be reproduced
upstream; these numbers are here mostly to indicate that these performance
improvements are not hypothetical, and show the benefits we're hoping to achieve
on our real workloads. 'citc1' is closest to large-dir-repo with one of our
pathological cases, 'citc2' is an arbitrary repo and closer to "average".

I'm not claiming anything less than a 5% speed win as improvements due to this
change; these are probably eiter measurement artifacts or constant time
improvements. The numbers that aren't changing are shown primarily to prove that
this doesn't make anything worse in any case I plan on testing during this
series.

'before' is hg from commit c83ad576. 'N' indicates narrow in use, 'T' indicates
treemanifest in use.

    hg status:
    repo  | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before
    ------+---+---+------------------------+-----------------------+------------
    m-u   |   |   | 2.284 s +-  0.022 s    | 2.274 s +-  0.021 s   |  99.6%
    m-u   |   | x | 2.289 s +-  0.008 s    | 2.284 s +-  0.028 s   |  99.8%
    m-u   | x |   | 430.8 ms +-   3.1 ms   | 424.5 ms +-   3.2 ms  |  98.5%
    m-u   | x | x | 429.8 ms +-   2.5 ms   | 425.8 ms +-   3.7 ms  |  99.1%
    l-d-r |   |   | 681.3 ms +-   5.5 ms   | 689.6 ms +-   8.0 ms  | 101.2%
    l-d-r |   | x | 666.8 ms +-  21.8 ms   | 672.5 ms +-  14.9 ms  | 100.9%
    l-d-r | x |   | 282.6 ms +-   1.8 ms   | 203.0 ms +-   1.2 ms  |  71.8% <--
    l-d-r | x | x | 275.2 ms +-   3.9 ms   | 199.3 ms +-   3.5 ms  |  72.4% <--
    citc1 | x | x | 1.023 s +-  0.011 s    | 398.6 ms +-   9.2 ms  |  39.0% <--
    citc2 | x | x | 297.9 ms +-   4.4 ms   | 289.6 ms +-   4.2 ms  |  97.2%

    hg status --change .:
    repo  | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before
    ------+---+---+------------------------+-----------------------+------------
    m-u   |   |   | 478.2 ms +-   2.0 ms   | 476.9 ms +-   3.7 ms  |  99.7%
    m-u   |   | x | 169.5 ms +-   2.7 ms   | 169.5 ms +-   2.5 ms  | 100.0%
    m-u   | x |   | 477.0 ms +-   2.4 ms   | 476.1 ms +-   1.4 ms  |  99.8%
    m-u   | x | x | 124.7 ms +-   1.9 ms   | 124.2 ms +-   3.3 ms  |  99.6%
    l-d-r |   |   | 97.4 ms +-   1.2 ms    | 96.5 ms +-   1.2 ms   |  99.1%
    l-d-r |   | x | 4.778 s +-  0.018 s    | 4.774 s +-  0.011 s   |  99.9%
    l-d-r | x |   | 99.9 ms +-   1.1 ms    | 98.8 ms +-   1.3 ms   |  98.9%
    l-d-r | x | x | 848.7 ms +-   7.1 ms   | 849.4 ms +-   6.5 ms  | 100.1%
    citc1 | x | x | 4.250 s +-  0.051 s    | 4.283 s +-  0.042 s   | 100.8%
    citc2 | x | x | 341.5 ms +-   4.7 ms   | 341.5 ms +-   4.1 ms  | 100.0%

    hg update $rev^; hg update $rev:
    repo  | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before
    ------+---+---+------------------------+-----------------------+------------
    m-u   |   |   | 4.357 s +-  0.032 s    | 4.312 s +-  0.093 s   |  99.0%
    m-u   |   | x | 3.599 s +-  0.061 s    | 3.592 s +-  0.071 s   |  99.8%
    m-u   | x |   | 1.815 s +-  0.012 s    | 1.816 s +-  0.013 s   | 100.1%
    m-u   | x | x | 1.110 s +-  0.009 s    | 1.106 s +-  0.005 s   |  99.6%
    l-d-r |   |   | 527.1 ms +-   7.8 ms   | 523.3 ms +-   6.5 ms  |  99.3%
    l-d-r |   | x | 8.835 s +-  0.067 s    | 8.825 s +-  0.064 s   |  99.9%
    l-d-r | x |   | 313.0 ms +-   2.2 ms   | 312.1 ms +-   1.2 ms  |  99.7%
    l-d-r | x | x | 1.780 s +-  0.011 s    | 1.799 s +-  0.013 s   | 101.1%
    citc1 | x | x | 6.825 s +-  0.262 s    | 6.707 s +-  0.353 s   |  98.3%
    citc2 | x | x | 776.4 ms +-   4.5 ms   | 781.3 ms +-   6.3 ms  | 100.6%

    hg diff:
    repo  | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before
    ------+---+---+------------------------+-----------------------+------------
    m-u   |   |   | 1.519 s +-  0.015 s    | 1.525 s +-  0.017 s   | 100.4%
    m-u   |   | x | 1.512 s +-  0.010 s    | 1.517 s +-  0.027 s   | 100.3%
    m-u   | x |   | 420.0 ms +-   3.2 ms   | 417.1 ms +-   1.9 ms  |  99.3%
    m-u   | x | x | 415.0 ms +-   3.8 ms   | 415.7 ms +-   2.7 ms  | 100.2%
    l-d-r |   |   | 220.8 ms +-   4.0 ms   | 220.8 ms +-   3.7 ms  | 100.0%
    l-d-r |   | x | 216.6 ms +-   7.5 ms   | 211.4 ms +-   2.1 ms  |  97.6%
    l-d-r | x |   | 111.9 ms +-   1.8 ms   | 112.0 ms +-   1.5 ms  | 100.1%
    l-d-r | x | x | 111.4 ms +-   1.4 ms   | 110.2 ms +-   1.0 ms  |  98.9%
    citc1 | x | x | 268.7 ms +-   2.3 ms   | 269.6 ms +-   2.8 ms  | 100.3%
    citc2 | x | x | 273.5 ms +-   5.5 ms   | 273.9 ms +-   3.7 ms  | 100.1%

    hg diff -c .:
    repo  | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before
    ------+---+---+--------------------------+-----------------------+----------
    m-u   |   |   | 497.1 ms +-   1.4 ms   | 500.1 ms +-   2.4 ms  | 100.6%
    m-u   |   | x | 195.3 ms +-  13.2 ms   | 191.6 ms +-   3.0 ms  |  98.1%
    m-u   | x |   | 476.8 ms +-   1.9 ms   | 476.7 ms +-   2.3 ms  | 100.0%
    m-u   | x | x | 122.8 ms +-   2.1 ms   | 122.9 ms +-   2.0 ms  | 100.1%
    l-d-r |   |   | 99.3 ms +-   2.3 ms    | 98.8 ms +-   1.7 ms   |  99.5%
    l-d-r |   | x | 4.875 s +-  0.041 s    | 4.847 s +-  0.038 s   |  99.4%
    l-d-r | x |   | 98.5 ms +-   1.2 ms    | 98.9 ms +-   1.3 ms   | 100.4%
    l-d-r | x | x | 864.6 ms +-   7.4 ms   | 855.4 ms +-   6.6 ms  |  98.9%
    citc1 | x | x | 4.505 s +-  0.060 s    | 4.466 s +-  0.036 s   |  99.1%
    citc2 | x | x | 368.0 ms +-   4.0 ms   | 365.5 ms +-   6.3 ms  |  99.3%

Differential Revision: https://phab.mercurial-scm.org/D4131

  $ cat > loop.py <<EOF
  > from __future__ import absolute_import
  > import time
  > from mercurial import commands, registrar
  > 
  > cmdtable = {}
  > command = registrar.command(cmdtable)
  > 
  > class incrementingtime(object):
  >     def __init__(self):
  >         self._time = 0.0
  >     def __call__(self):
  >         self._time += 0.25
  >         return self._time
  > time.time = incrementingtime()
  > 
  > @command(b'loop',
  >     [(b'', b'total', b'', b'override for total'),
  >     (b'', b'nested', False, b'show nested results'),
  >     (b'', b'parallel', False, b'show parallel sets of results')],
  >     b'hg loop LOOPS',
  >     norepo=True)
  > def loop(ui, loops, **opts):
  >     loops = int(loops)
  >     total = None
  >     if loops >= 0:
  >         total = loops
  >     if opts.get('total', None):
  >         total = int(opts.get('total'))
  >     nested = False
  >     if opts.get('nested', None):
  >         nested = True
  >     loops = abs(loops)
  > 
  >     progress = ui.makeprogress(topiclabel, unit='loopnum', total=total)
  >     other = ui.makeprogress('other', unit='othernum', total=total)
  >     for i in range(loops):
  >         progress.update(i, item=getloopitem(i))
  >         if opts.get('parallel'):
  >             other.update(i, item='other.%d' % i)
  >         if nested:
  >             nested_steps = 2
  >             if i and i % 4 == 0:
  >                 nested_steps = 5
  >             nested = ui.makeprogress('nested', unit='nestnum',
  >                                      total=nested_steps)
  >             for j in range(nested_steps):
  >                 nested.update(j, item='nested.%d' % j)
  >             nested.complete()
  >     progress.complete()
  > 
  > topiclabel = 'loop'
  > def getloopitem(i):
  >     return 'loop.%d' % i
  > 
  > EOF

  $ cp $HGRCPATH $HGRCPATH.orig
  $ echo "[extensions]" >> $HGRCPATH
  $ echo "progress=" >> $HGRCPATH
  $ echo "loop=`pwd`/loop.py" >> $HGRCPATH
  $ echo "[progress]" >> $HGRCPATH
  $ echo "format = topic bar number" >> $HGRCPATH
  $ echo "assume-tty=1" >> $HGRCPATH
  $ echo "width=60" >> $HGRCPATH

test default params, display nothing because of delay

  $ hg -y loop 3
  $ echo "delay=0" >> $HGRCPATH
  $ echo "refresh=0" >> $HGRCPATH

test with delay=0, refresh=0

  $ hg -y loop 3
  \r (no-eol) (esc)
  loop [                                                ] 0/3\r (no-eol) (esc)
  loop [===============>                                ] 1/3\r (no-eol) (esc)
  loop [===============================>                ] 2/3\r (no-eol) (esc)
                                                              \r (no-eol) (esc)
no progress with --quiet
  $ hg -y loop 3 --quiet

test plain mode exception
  $ HGPLAINEXCEPT=progress hg -y loop 1
  \r (no-eol) (esc)
  loop [                                                ] 0/1\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

test nested short-lived topics (which shouldn't display with nestdelay):

  $ hg -y loop 3 --nested
  \r (no-eol) (esc)
  loop [                                                ] 0/3\r (no-eol) (esc)
  loop [===============>                                ] 1/3\r (no-eol) (esc)
  loop [===============================>                ] 2/3\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

Test nested long-lived topic which has the same name as a short-lived
peer. We shouldn't get stuck showing the short-lived inner steps, and
should go back to skipping the inner steps when the slow nested step
finishes.

  $ hg -y loop 7 --nested
  \r (no-eol) (esc)
  loop [                                                ] 0/7\r (no-eol) (esc)
  loop [=====>                                          ] 1/7\r (no-eol) (esc)
  loop [============>                                   ] 2/7\r (no-eol) (esc)
  loop [===================>                            ] 3/7\r (no-eol) (esc)
  loop [==========================>                     ] 4/7\r (no-eol) (esc)
  nested [==========================>                   ] 3/5\r (no-eol) (esc)
  nested [===================================>          ] 4/5\r (no-eol) (esc)
  loop [=================================>              ] 5/7\r (no-eol) (esc)
  loop [========================================>       ] 6/7\r (no-eol) (esc)
                                                              \r (no-eol) (esc)


  $ hg --config progress.changedelay=0 -y loop 3 --nested
  \r (no-eol) (esc)
  loop [                                                ] 0/3\r (no-eol) (esc)
  nested [                                              ] 0/2\r (no-eol) (esc)
  nested [======================>                       ] 1/2\r (no-eol) (esc)
  loop [===============>                                ] 1/3\r (no-eol) (esc)
  nested [                                              ] 0/2\r (no-eol) (esc)
  nested [======================>                       ] 1/2\r (no-eol) (esc)
  loop [===============================>                ] 2/3\r (no-eol) (esc)
  nested [                                              ] 0/2\r (no-eol) (esc)
  nested [======================>                       ] 1/2\r (no-eol) (esc)
                                                              \r (no-eol) (esc)


test two topics being printed in parallel (as when we're doing a local
--pull clone, where you get the unbundle and bundle progress at the
same time):
  $ hg loop 3 --parallel
  \r (no-eol) (esc)
  loop [                                                ] 0/3\r (no-eol) (esc)
  loop [===============>                                ] 1/3\r (no-eol) (esc)
  loop [===============================>                ] 2/3\r (no-eol) (esc)
                                                              \r (no-eol) (esc)
test refresh is taken in account

  $ hg -y --config progress.refresh=100 loop 3

test format options 1

  $ hg -y --config 'progress.format=number topic item+2' loop 2
  \r (no-eol) (esc)
  0/2 loop lo\r (no-eol) (esc)
  1/2 loop lo\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

test format options 2

  $ hg -y --config 'progress.format=number item-3 bar' loop 2
  \r (no-eol) (esc)
  0/2 p.0 [                                                 ]\r (no-eol) (esc)
  1/2 p.1 [=======================>                         ]\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

test format options and indeterminate progress

  $ hg -y --config 'progress.format=number item bar' loop -- -2
  \r (no-eol) (esc)
  0 loop.0               [ <=>                              ]\r (no-eol) (esc)
  1 loop.1               [  <=>                             ]\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

make sure things don't fall over if count > total

  $ hg -y loop --total 4 6
  \r (no-eol) (esc)
  loop [                                                ] 0/4\r (no-eol) (esc)
  loop [===========>                                    ] 1/4\r (no-eol) (esc)
  loop [=======================>                        ] 2/4\r (no-eol) (esc)
  loop [===================================>            ] 3/4\r (no-eol) (esc)
  loop [===============================================>] 4/4\r (no-eol) (esc)
  loop [ <=>                                            ] 5/4\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

test immediate progress completion

  $ hg -y loop 0

test delay time estimates

#if no-chg

  $ cp $HGRCPATH.orig $HGRCPATH
  $ echo "[extensions]" >> $HGRCPATH
  $ echo "mocktime=$TESTDIR/mocktime.py" >> $HGRCPATH
  $ echo "progress=" >> $HGRCPATH
  $ echo "loop=`pwd`/loop.py" >> $HGRCPATH
  $ echo "[progress]" >> $HGRCPATH
  $ echo "assume-tty=1" >> $HGRCPATH
  $ echo "delay=25" >> $HGRCPATH
  $ echo "width=60" >> $HGRCPATH

  $ MOCKTIME=11 hg -y loop 8
  \r (no-eol) (esc)
  loop [=========>                                ] 2/8 1m07s\r (no-eol) (esc)
  loop [===============>                            ] 3/8 56s\r (no-eol) (esc)
  loop [=====================>                      ] 4/8 45s\r (no-eol) (esc)
  loop [==========================>                 ] 5/8 34s\r (no-eol) (esc)
  loop [================================>           ] 6/8 23s\r (no-eol) (esc)
  loop [=====================================>      ] 7/8 12s\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

  $ MOCKTIME=10000 hg -y loop 4
  \r (no-eol) (esc)
  loop [                                                ] 0/4\r (no-eol) (esc)
  loop [=========>                                ] 1/4 8h21m\r (no-eol) (esc)
  loop [====================>                     ] 2/4 5h34m\r (no-eol) (esc)
  loop [==============================>           ] 3/4 2h47m\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

  $ MOCKTIME=1000000 hg -y loop 4
  \r (no-eol) (esc)
  loop [                                                ] 0/4\r (no-eol) (esc)
  loop [=========>                                ] 1/4 5w00d\r (no-eol) (esc)
  loop [====================>                     ] 2/4 3w03d\r (no-eol) (esc)
  loop [=============================>           ] 3/4 11d14h\r (no-eol) (esc)
                                                              \r (no-eol) (esc)


  $ MOCKTIME=14000000 hg -y loop 4
  \r (no-eol) (esc)
  loop [                                                ] 0/4\r (no-eol) (esc)
  loop [=========>                                ] 1/4 1y18w\r (no-eol) (esc)
  loop [===================>                     ] 2/4 46w03d\r (no-eol) (esc)
  loop [=============================>           ] 3/4 23w02d\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

Non-linear progress:

  $ MOCKTIME='20 20 20 20 20 20 20 20 20 20 500 500 500 500 500 20 20 20 20 20' hg -y loop 20
  \r (no-eol) (esc)
  loop [=>                                      ]  1/20 6m21s\r (no-eol) (esc)
  loop [===>                                    ]  2/20 6m01s\r (no-eol) (esc)
  loop [=====>                                  ]  3/20 5m41s\r (no-eol) (esc)
  loop [=======>                                ]  4/20 5m21s\r (no-eol) (esc)
  loop [=========>                              ]  5/20 5m01s\r (no-eol) (esc)
  loop [===========>                            ]  6/20 4m41s\r (no-eol) (esc)
  loop [=============>                          ]  7/20 4m21s\r (no-eol) (esc)
  loop [===============>                        ]  8/20 4m01s\r (no-eol) (esc)
  loop [================>                      ]  9/20 25m40s\r (no-eol) (esc)
  loop [===================>                    ] 10/20 1h06m\r (no-eol) (esc)
  loop [=====================>                  ] 11/20 1h13m\r (no-eol) (esc)
  loop [=======================>                ] 12/20 1h07m\r (no-eol) (esc)
  loop [========================>              ] 13/20 58m19s\r (no-eol) (esc)
  loop [===========================>            ] 14/20 7m09s\r (no-eol) (esc)
  loop [=============================>          ] 15/20 3m38s\r (no-eol) (esc)
  loop [===============================>        ] 16/20 2m15s\r (no-eol) (esc)
  loop [=================================>      ] 17/20 1m27s\r (no-eol) (esc)
  loop [====================================>     ] 18/20 52s\r (no-eol) (esc)
  loop [======================================>   ] 19/20 25s\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

Time estimates should not fail when there's no end point:
  $ MOCKTIME=11 hg -y loop -- -4
  \r (no-eol) (esc)
  loop [ <=>                                              ] 2\r (no-eol) (esc)
  loop [  <=>                                             ] 3\r (no-eol) (esc)
                                                              \r (no-eol) (esc)

#endif

test line trimming by '[progress] width', when progress topic contains
multi-byte characters, of which length of byte sequence and columns in
display are different from each other.

  $ cp $HGRCPATH.orig $HGRCPATH
  $ cat >> $HGRCPATH <<EOF
  > [extensions]
  > progress=
  > loop=`pwd`/loop.py
  > [progress]
  > assume-tty = 1
  > delay = 0
  > refresh = 0
  > EOF

  $ rm -f loop.pyc
  $ cat >> loop.py <<EOF
  > # use non-ascii characters as topic label of progress
  > # 2 x 4 = 8 columns, but 3 x 4 = 12 bytes
  > topiclabel = u'\u3042\u3044\u3046\u3048'.encode('utf-8')
  > EOF

  $ cat >> $HGRCPATH <<EOF
  > [progress]
  > format = topic number
  > width= 12
  > EOF

  $ hg --encoding utf-8 -y loop --total 3 3
  \r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 0/3\r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 1/3\r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 2/3\r (no-eol) (esc)
              \r (no-eol) (esc)

test calculation of bar width, when progress topic contains multi-byte
characters, of which length of byte sequence and columns in display
are different from each other.

  $ cat >> $HGRCPATH <<EOF
  > [progress]
  > format = topic bar
  > width= 21
  > # progwidth should be 9 (= 21 - (8+1) - 3)
  > EOF

  $ hg --encoding utf-8 -y loop --total 3 3
  \r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 [         ]\r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 [==>      ]\r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\xe3\x81\x88 [=====>   ]\r (no-eol) (esc)
                       \r (no-eol) (esc)

test trimming progress items, when they contain multi-byte characters,
of which length of byte sequence and columns in display are different
from each other.

  $ rm -f loop.pyc
  $ rm -Rf __pycache__
  $ cat >> loop.py <<EOF
  > # use non-ascii characters as loop items of progress
  > loopitems = [
  >     u'\u3042\u3044'.encode('utf-8'), # 2 x 2 = 4 columns
  >     u'\u3042\u3044\u3046'.encode('utf-8'), # 2 x 3 = 6 columns
  >     u'\u3042\u3044\u3046\u3048'.encode('utf-8'), # 2 x 4 = 8 columns
  > ]
  > def getloopitem(i):
  >     return loopitems[i % len(loopitems)]
  > EOF

  $ cat >> $HGRCPATH <<EOF
  > [progress]
  > # trim at tail side
  > format = item+6
  > EOF

  $ hg --encoding utf-8 -y loop --total 3 3
  \r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84  \r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\r (no-eol) (esc)
                       \r (no-eol) (esc)

  $ cat >> $HGRCPATH <<EOF
  > [progress]
  > # trim at left side
  > format = item-6
  > EOF

  $ hg --encoding utf-8 -y loop --total 3 3
  \r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84  \r (no-eol) (esc)
  \xe3\x81\x82\xe3\x81\x84\xe3\x81\x86\r (no-eol) (esc)
  \xe3\x81\x84\xe3\x81\x86\xe3\x81\x88\r (no-eol) (esc)
                       \r (no-eol) (esc)