[j-nsp] why is "show log messages | last 10" so slow?

[Saku Ytti]

I suspect this change would be difficult one.

XML RPC is the first class citizen, CLI is generated from the XML.

Naively we'd might think the CLI forks cat and this is simple fix. But
because JunOS is actually designed right in this respect, this is not
what it does.


ytti at r24.labxtx01.us.bb-re0> show log messages | display xml rpc
<rpc-reply xmlns:junos="http://xml.juniper.net/junos/18.1I0/junos">
    <rpc>
        <get-log>
                <filename>messages</filename>
        </get-log>
    </rpc>
    <cli>
        <banner>{master}</banner>
    </cli>
</rpc-reply>



So this is the information the RPC backend gets. Curiously:

ytti at r24.labxtx01.us.bb-re0> show log messages | last 50 |display xml rpc
<rpc-reply xmlns:junos="http://xml.juniper.net/junos/18.1I0/junos">
    <rpc>
        <get-log>
                <filename>messages</filename>
        </get-log>
    </rpc>
    <rpc>
        <get-log>
                <filename>messages</filename>
        </get-log>
    </rpc>
    <cli>
        <banner>{master}</banner>
    </cli>
</rpc-reply>

{master}
ytti at r24.labxtx01.us.bb-re0>


Dunno why the 'get-log' is there twice. However, the salient point is,
we're not passing the 'last 50' the RPC call, the backend has no
awareness of this. The 'last 50' is purely CLI construct. The
designers could have chosen that 'last N' is passed to RPC always as
an argument, and never implemented in CLI, and each RPC call has to
implement it. It is debatable which is the right call.

Changing this post-fact would be challenge, not only would they need
to start passing 'last N' as argument to RPC call, they'd also need
boolean in RPC reply to tell if 'last N' was honoured or not, so that
CLI could omit from doing it again when RPC call is implementing it.



Interestingly someone pointed out on another forum that 'show config'
is fast, while 'show config | count' it slow, implying some sort of
streaming. And sure enough 'show config | display xml rpc' does not
work, perhaps Juniper implemented optimisation where CLI does not use
RPC call for 'show config' to stream it?



On Mon, 29 Oct 2018 at 18:48, Hugo Slabbert <hugo at slabnet.com> wrote:
>
> On Mon 2018-Oct-29 16:28:12 +0000, Anderson, Charles R <cra at wpi.edu> wrote:
>
> >Why is "show log messages | last 10" so slow with a large log file when I
> >can go to the shell and run "tail -10 /var/log/messages" much more
> >quickly?
>
> Because it's an action that is done after the pipe rather than being the
> action itself, so it's equivalent to `cat /var/log/messages | tail -n 10`
> not directly to `tail -n 10 /var/log/messages`.  It's a generic pipe action
> that can be applied to any text output, e.g. the output of a regular
> operational "show" command, but it's not a top-level command that does file
> processing itself like `tail` can.
>
> >Maybe JUNOS can borrow the implementation of the "tail" command to make it
> >quicker.
>
> They'd have to add a new top-level command or perhaps add a parameter to
> the `file show` operation, I'd think.  Probably doable, but not sure how
> much traction the feature request would get.
>
> --
> Hugo Slabbert       | email, xmpp/jabber: hugo at slabnet.com
> pgp key: B178313E   | also on Signal
> _______________________________________________
> juniper-nsp mailing list juniper-nsp at puck.nether.net
> https://puck.nether.net/mailman/listinfo/juniper-nsp



-- 
  ++ytti