Hi,

I made up a simple bash script (attached below) to compare 10,000 runs of tac|sed, grep|tail, plain grep:


tac + sed method (tac /var/log/messages | sed -n '/pakfire:/{p;/Pakfire.*started/q}' > /dev/null)

real    0m28.365s
user    0m31.261s
sys     0m17.783s

grep + tail method (grep pakfire /var/log/messages | tail -20 > /dev/null)

real    1m7.391s
user    1m0.450s
sys     1m2.278s

plain grep method (grep pakfire /var/log/messages > /dev/null)

real    0m24.822s
user    0m16.607s
sys     0m9.018s

Although a simple "grep pakfire" seems to be the fastest solution at first glance, you would have to process a lot of data in Perl afterwards, loosing any benefit.
The tac+sed method already returns only the desired lines and is still faster than the previously used grep+tail technique.
Therefore, I would want to argue that this method is suitable!

What do you think? Is this test acceptable?

Regards
Leo


#!/bin/bash
tacsed () {
         for run in {1..10000}; do
                 tac /var/log/messages | sed -n '/pakfire:/{p;/Pakfire.*started/q}' > /dev/null
         done
}
greptail () {
         for run in {1..10000}; do
                 grep pakfire /var/log/messages | tail -20 > /dev/null
         done
}
plaingrep () {
         for run in {1..10000}; do
                 grep pakfire /var/log/messages > /dev/null
         done
}
echo -e "\ntac + sed method"
time tacsed
echo -e "\ngrep + tail method"
time greptail
echo -e "\nplain grep method"
time plaingrep



Am 02.12.2021 um 17:30 schrieb Leo Hofmann:
> Hi,
>
> Am 02.12.2021 um 16:59 schrieb Michael Tremer:
>> Hello,
>>
>>> On 2 Dec 2021, at 15:39, Leo-Andres Hofmann <hofmann(a)leo-andres.de> wrote:
>>>
>>> Currently the page becomes unresponsive while Pakfire is busy.
>>> This patch implements a AJAX/JSON driven log output, to provide
>>> continuous information to the user while Pakfire is running.
>>>
>>> The output is updated 1x per second, if the load should be too high,
>>> the interval can be change by writing to "pakfire.refreshInterval".
>>>
>>> Signed-off-by: Leo-Andres Hofmann <hofmann(a)leo-andres.de>
>>> ---
>>> html/cgi-bin/pakfire.cgi     | 153 ++++++++++++++++++----
>>> html/html/include/pakfire.js | 241 +++++++++++++++++++++++++++++++++++
>>> 2 files changed, 368 insertions(+), 26 deletions(-)
>>> create mode 100644 html/html/include/pakfire.js
>>>
>>> diff --git a/html/cgi-bin/pakfire.cgi b/html/cgi-bin/pakfire.cgi
>>> index 7957bc154..e5f5f7d6a 100644
>>> --- a/html/cgi-bin/pakfire.cgi
>>> +++ b/html/cgi-bin/pakfire.cgi
>>> @@ -36,8 +36,11 @@ my %color = ();
>>> my %pakfiresettings = ();
>>> my %mainsettings = ();
>>>
>>> -&Header::showhttpheaders();
>>> +# Load general settings
>>> +&General::readhash("${General::swroot}/main/settings", \%mainsettings);
>>> +&General::readhash("/srv/web/ipfire/html/themes/ipfire/include/colors.txt", \%color);
>>>
>>> +# Get CGI request data
>>> $cgiparams{'ACTION'} = '';
>>> $cgiparams{'VALID'} = '';
>>>
>>> @@ -46,12 +49,102 @@ $cgiparams{'DELPAKS'} = '';
>>>
>>> &Header::getcgihash(\%cgiparams);
>>>
>>> -&General::readhash("${General::swroot}/main/settings", \%mainsettings);
>>> -&General::readhash("/srv/web/ipfire/html/themes/ipfire/include/colors.txt", \%color);
>>> +### Process AJAX/JSON request ###
>>> +if($cgiparams{'ACTION'} eq 'json-getstatus') {
>>> +    # Send HTTP headers
>>> +    _start_json_output();
>>> +
>>> +    # Collect Pakfire status and log messages
>>> +    my %status = (
>>> +        'running' => &_is_pakfire_busy() || "0",
>>> +        'running_since' => &General::age("$Pakfire::lockfile") || "0s",
>>> +        'reboot' => (-e "/var/run/need_reboot") || "0"
>>> +    );
>>> +    my @messages = `tac /var/log/messages | sed -n '/pakfire:/{p;/Pakfire.*started/q}'`;
>>> +
>>> +    # Start JSON file
>>> +    print "{\n";
>>> +
>>> +    foreach my $key (keys %status) {
>>> +        my $value = $status{$key};
>>> +        print qq{\t"$key": "$value",\n};
>>> +    }
>>> +
>>> +    # Print sanitized messages in reverse order to undo previous "tac"
>>> +    print qq{\t"messages": [\n};
>>> +    for my $index (reverse (0 .. $#messages)) {
>>> +        my $line = $messages[$index];
>>> +        $line =~ s/[[:cntrl:]<>&\\]+//g;
>>> +
>>> +        print qq{\t\t"$line"};
>>> +        print ",\n" unless $index < 1;
>>> +    }
>>> +    print "\n\t]\n";
>> What is the reason to “tac” the log file first and then reverse the order again?
>>
>> Is it just to limit the length of the JSON array?
>>
>> It might be faster to read the entire file, grep out what we need and then throw away most of the array. Or push a line to the end of the array and remove one from the beginning if it is longer than a certain threshold.
>
> I wanted to make sure that only the output of the current Pakfire run is shown. Therefore, I use tac and sed to read the logfile backwards until the last "Pakfire ... started!" header is reached.
> This works very well, but then of course the messages array is also in reverse order.
>
> All the ideas I had required some form of "reverse", or I had to load the entire file in Perl and check every line. I assumed that tac & sed would be more efficient than any Perl solution I could come up with. I'll try to time this and report back!
>
> Leo
>
>>
>>> +
>>> +    # Finalize JSON file & stop
>>> +    print "}";
>>> +    exit;
>>> +}
>>> +
>>> +### Start pakfire page ###
>>> +&Header::showhttpheaders();
>>> +
>>> +###--- HTML HEAD ---###
>>> +my $extraHead = <<END
>>> +<style>
>>> +    /* Pakfire log viewer */
>>> +    section#pflog-header {
>>> +        width: 100%;
>>> +        display: flex;
>>> +        text-align: left;
>>> +        align-items: center;
>>> +        column-gap: 20px;
>>> +    }
>>> +    #pflog-header > div:last-child {
>>> +        margin-left: auto;
>>> +        margin-right: 20px;
>>> +    }
>>> +    #pflog-header span {
>>> +        line-height: 1.3em;
>>> +    }
>>> +    #pflog-header span:empty::before {
>>> +        content: "\\200b"; /* zero width space */
>>> +    }
>>> +
>>> +    pre#pflog-messages {
>>> +        margin-top: 0.7em;
>>> +        padding-top: 0.7em;
>>> +        border-top: 0.5px solid $Header::bordercolour;
>>>
>>> -&Header::openpage($Lang::tr{'pakfire configuration'}, 1);
>>> +        text-align: left;
>>> +        min-height: 15em;
>>> +        overflow-x: auto;
>>> +    }
>>> +</style>
>>> +
>>> +<script src="/include/pakfire.js"></script>
>>> +<script>
>>> +    // Translations
>>> +    pakfire.i18n.load({
>>> +        'working': '$Lang::tr{'pakfire working'}',
>>> +        'finished': 'Pakfire is finished! Please check the log output.',
>>> +        'since': '$Lang::tr{'since'} ', //(space is intentional)
>>> +
>>> +        'link_return': '<a href="$ENV{'SCRIPT_NAME'}">Return to Pakfire</a>',
>>> +        'link_reboot': '<a href="/cgi-bin/shutdown.cgi">$Lang::tr{'needreboot'}</a>'
>>> +    });
>>> +
>>> +    // AJAX auto refresh interval
>>> +    pakfire.refreshInterval = 1000;
>>> +</script>
>>> +END
>>> +;
>>> +###--- END HTML HEAD ---###
>>> +
>>> +&Header::openpage($Lang::tr{'pakfire configuration'}, 1, $extraHead);
>>> &Header::openbigbox('100%', 'left', '', $errormessage);
>>>
>>> +# Process Pakfire commands
>>> if (($cgiparams{'ACTION'} eq 'install') && (! &_is_pakfire_busy())) {
>>>     my @pkgs = split(/\|/, $cgiparams{'INSPAKS'});
>>>     if ("$cgiparams{'FORCE'}" eq "on") {
>>> @@ -170,29 +263,30 @@ if ($errormessage) {
>>>     &Header::closebox();
>>> }
>>>
>>> -# Check if pakfire is already running.
>>> -if (&_is_pakfire_busy()) {
>>> -    &Header::openbox( 'Waiting', 1, "<meta http-equiv='refresh' content='10;'>" );
>>> -    print <<END;
>>> -    <table>
>>> -        <tr><td>
>>> -                <img src='/images/indicator.gif' alt='$Lang::tr{'active'}' title='$Lang::tr{'active'}' />&nbsp;
>>> -            <td>
>>> -                $Lang::tr{'pakfire working'}
>>> -        <tr><td colspan='2' align='center'>
>>> -            <form method='post' action='$ENV{'SCRIPT_NAME'}'>
>>> -                <input type='image' alt='$Lang::tr{'reload'}' title='$Lang::tr{'reload'}' src='/images/view-refresh.png' />
>>> -            </form>
>>> -        <tr><td colspan='2' align='left'><code>
>>> -END
>>> -    my @output = `grep pakfire /var/log/messages | tail -20`;
>>> -    foreach (@output) {
>>> -        print "$_<br>";
>>> -    }
>>> -    print <<END;
>>> -            </code>
>>> -        </table>
>>> +# Show log output while Pakfire is running
>>> +if(&_is_pakfire_busy()) {
>>> +    &Header::openbox("100%", "center", "Pakfire");
>>> +
>>> +    print <<END
>>> +<section id="pflog-header">
>>> +    <div><img src="/images/indicator.gif" alt="$Lang::tr{'active'}" title="$Lang::tr{'pagerefresh'}"></div>
>>> +    <div>
>>> +        <span id="pflog-status">$Lang::tr{'pakfire working'}</span><br>
>>> +        <span id="pflog-time"></span><br>
>>> +        <span id="pflog-action"></span>
>>> +    </div>
>>> +    <div><a href="$ENV{'SCRIPT_NAME'}"><img src="/images/view-refresh.png" alt="$Lang::tr{'refresh'}" title="$Lang::tr{'refresh'}"></a></div>
>>> +</section>
>>> +
>>> +<!-- Pakfire log messages -->
>>> +<pre id="pflog-messages"></pre>
>>> +<script>
>>> +    pakfire.running = true;
>>> +</script>
>>> +
>>> END
>>> +;
>>> +
>>>     &Header::closebox();
>>>     &Header::closebigbox();
>>>     &Header::closepage();
>>> @@ -320,3 +414,10 @@ sub _is_pakfire_busy {
>>>     # Test presence of PID or lockfile
>>>     return (($pakfire_pid) || (-e "$Pakfire::lockfile"));
>>> }
>>> +
>>> +# Send HTTP headers
>>> +sub _start_json_output {
>>> +    print "Cache-Control: no-cache, no-store\n";
>>> +    print "Content-Type: application/json\n";
>>> +    print "\n"; # End of HTTP headers
>>> +}
>>> diff --git a/html/html/include/pakfire.js b/html/html/include/pakfire.js
>>> new file mode 100644
>>> index 000000000..0950870e0
>>> --- /dev/null
>>> +++ b/html/html/include/pakfire.js
>>> @@ -0,0 +1,241 @@
>>> +/*#############################################################################
>>> +# #
>>> +# IPFire.org - A linux based firewall                                         #
>>> +# Copyright (C) 2007-2021  IPFire Team <info(a)ipfire.org>                     #
>>> +# #
>>> +# This program is free software: you can redistribute it and/or modify        #
>>> +# it under the terms of the GNU General Public License as published by        #
>>> +# the Free Software Foundation, either version 3 of the License, or           #
>>> +# (at your option) any later version.                                         #
>>> +# #
>>> +# This program is distributed in the hope that it will be useful,             #
>>> +# but WITHOUT ANY WARRANTY; without even the implied warranty of              #
>>> +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the               #
>>> +# GNU General Public License for more details.                                #
>>> +# #
>>> +# You should have received a copy of the GNU General Public License           #
>>> +# along with this program.  If not, see <http://www.gnu.org/licenses/>.       #
>>> +# #
>>> +#############################################################################*/
>>> +
>>> +"use strict";
>>> +
>>> +// Pakfire Javascript functions (requires jQuery)
>>> +class PakfireJS {
>>> +    constructor() {
>>> +        //--- Public properties ---
>>> +        // Translation strings
>>> +        this.i18n = new PakfireI18N();
>>> +
>>> +        //--- Private properties ---
>>> +        // Status flags (access outside constructor only with setter/getter)
>>> +        this._states = Object.create(null);
>>> +        this._states.running = false;
>>> +        this._states.reboot = false;
>>> +
>>> +        // Status refresh helper
>>> +        this._autoRefresh = {
>>> +            delay: 1000, //Delay between requests (default: 1s)
>>> +            jsonAction: 'getstatus', //CGI POST action parameter
>>> +            timeout: 5000, //XHR timeout (5s)
>>> +
>>> +            delayTimer: null, //setTimeout reference
>>> +            jqXHR: undefined, //jQuery.ajax promise reference
>>> +            get runningDelay() { //Waiting for end of delay
>>> +                return (this.delayTimer !== null);
>>> +            },
>>> +            get runningXHR() { //Waiting for CGI response
>>> +                return (this.jqXHR && (this.jqXHR.state() === 'pending'));
>>> +            },
>>> +            get isRunning() {
>>> +                return (this.runningDelay || this.runningXHR);
>>> +            }
>>> +        };
>>> +    }
>>> +
>>> +    //### Public properties ###
>>> +
>>> +    // Pakfire is running (true/false)
>>> +    set running(state) {
>>> +        if(this._states.running !== state) {
>>> +            this._states.running = state;
>>> +            this._states_onChange('running');
>>> +        }
>>> +    }
>>> +    get running() {
>>> +        return this._states.running;
>>> +    }
>>> +
>>> +    // Reboot needed (true/false)
>>> +    set reboot(state) {
>>> +        if(this._states.reboot !== state) {
>>> +            this._states.reboot = state;
>>> +            this._states_onChange('reboot');
>>> +        }
>>> +    }
>>> +    get reboot() {
>>> +        return this._states.reboot;
>>> +    }
>>> +
>>> +    // Status refresh interval in ms
>>> +    set refreshInterval(delay) {
>>> +        if(delay < 500) {
>>> +            delay = 500; //enforce reasonable minimum
>>> +        }
>>> +        this._autoRefresh.delay = delay;
>>> +    }
>>> +    get refreshInterval() {
>>> +        return this._autoRefresh.delay;
>>> +    }
>>> +
>>> +    // Document loaded (call once from jQuery.ready)
>>> +    documentReady() {
>>> +        // Status refresh late start
>>> +        if(this.running && (! this._autoRefresh.isRunning)) {
>>> +            this._autoRefresh_runNow();
>>> +        }
>>> +    }
>>> +
>>> +    //### Private properties ###
>>> +
>>> +    // Pakfire status change handler
>>> +    // property: Affected status (running, reboot, ...)
>>> +    _states_onChange(property) {
>>> +        // Always update UI
>>> +        if(this.running) {
>>> + $('#pflog-status').text(this.i18n.get('working'));
>>> +            $('#pflog-action').empty();
>>> +        } else {
>>> + $('#pflog-status').text(this.i18n.get('finished'));
>>> +            if(this.reboot) { //Enable return or reboot links in UI
>>> + $('#pflog-action').html(this.i18n.get('link_reboot'));
>>> +            } else {
>>> + $('#pflog-action').html(this.i18n.get('link_return'));
>>> +            }
>>> +        }
>>> +
>>> +        // Start/stop status refresh if Pakfire started/stopped
>>> +        if(property === 'running') {
>>> +            if(this.running) {
>>> +                this._autoRefresh_runNow();
>>> +            } else {
>>> +                this._autoRefresh_clearSchedule();
>>> +            }
>>> +        }
>>> +    }
>>> +
>>> +    //--- Status refresh scheduling functions ---
>>> +
>>> +    // Immediately perform AJAX status refresh request
>>> +    _autoRefresh_runNow() {
>>> +        if(this._autoRefresh.runningXHR) {
>>> +            return; // Don't send multiple requests
>>> +        }
>>> +        this._autoRefresh_clearSchedule(); // Stop scheduled refresh, will send immediately
>>> +
>>> +        // Send AJAX request, attach listeners
>>> +        this._autoRefresh.jqXHR = this._JSON_get(this._autoRefresh.jsonAction, this._autoRefresh.timeout);
>>> +        this._autoRefresh.jqXHR.done(function() { // Request succeeded
>>> +            if(this.running) { // Keep refreshing while Pakfire is running
>>> +                this._autoRefresh_scheduleRun();
>>> +            }
>>> +        });
>>> +        this._autoRefresh.jqXHR.fail(function() { // Request failed
>>> +            this._autoRefresh_scheduleRun(); // Try refreshing until valid status is received
>>> +        });
>>> +    }
>>> +
>>> +    // Schedule next refresh
>>> +    _autoRefresh_scheduleRun() {
>>> +        if(this._autoRefresh.runningDelay || this._autoRefresh.runningXHR) {
>>> +            return; // Refresh already scheduled or in progress
>>> +        }
>>> +        this._autoRefresh.delayTimer = window.setTimeout(function() {
>>> +            this._autoRefresh.delayTimer = null;
>>> +            this._autoRefresh_runNow();
>>> +        }.bind(this), this._autoRefresh.delay);
>>> +    }
>>> +
>>> +    // Stop scheduled refresh (can still be refreshed up to 1x if XHR is already sent)
>>> +    _autoRefresh_clearSchedule() {
>>> +        if(this._autoRefresh.runningDelay) {
>>> + window.clearTimeout(this._autoRefresh.delayTimer);
>>> +            this._autoRefresh.delayTimer = null;
>>> +        }
>>> +    }
>>> +
>>> +    //--- JSON request & data handling ---
>>> +
>>> +    // Load JSON data from Pakfire CGI, using a POST request
>>> +    // action: POST paramter "json-[action]"
>>> +    // maxTime: XHR timeout, 0 = no timeout
>>> +    _JSON_get(action, maxTime = 0) {
>>> +        return $.ajax({
>>> +            url: '/cgi-bin/pakfire.cgi',
>>> +            method: 'POST',
>>> +            timeout: maxTime,
>>> +            context: this,
>>> +            data: {'ACTION': `json-${action}`},
>>> +            dataType: 'json' //automatically check and convert result
>>> +        })
>>> +            .done(function(response) {
>>> +                this._JSON_process(action, response);
>>> +            });
>>> +    }
>>> +
>>> +    // Process successful response from Pakfire CGI
>>> +    // action: POST paramter "json-[action]" used to send request
>>> +    // data: JSON data object
>>> +    _JSON_process(action, data) {
>>> +        // Pakfire status refresh
>>> +        if(action === this._autoRefresh.jsonAction) {
>>> +            // Update status flags
>>> +            this.running = (data['running'] != '0');
>>> +            this.reboot = (data['reboot'] != '0');
>>> +
>>> +            // Update timer display
>>> +            if(this.running && data['running_since']) {
>>> +                $('#pflog-time').text(this.i18n.get('since') + data['running_since']);
>>> +            } else {
>>> +                $('#pflog-time').empty();
>>> +            }
>>> +
>>> +            // Print log messages
>>> +            let messages = "";
>>> +            data['messages'].forEach(function(line) {
>>> +                messages += `${line}\n`;
>>> +            });
>>> +            $('#pflog-messages').text(messages);
>>> +        }
>>> +    }
>>> +}
>>> +
>>> +// Simple translation strings helper
>>> +// Format: {key: "translation"}
>>> +class PakfireI18N {
>>> +    constructor() {
>>> +        this._strings = Object.create(null); //Object without prototypes
>>> +    }
>>> +
>>> +    // Get translation
>>> +    get(key) {
>>> + if(Object.prototype.hasOwnProperty.call(this._strings, key)) {
>>> +            return this._strings[key];
>>> +        }
>>> +        return `(undefined string '${key}')`;
>>> +    }
>>> +
>>> +    // Load key/translation object
>>> +    load(translations) {
>>> +        if(translations instanceof Object) {
>>> +            Object.assign(this._strings, translations);
>>> +        }
>>> +    }
>>> +}
>>> +
>>> +//### Initialize Pakfire ###
>>> +const pakfire = new PakfireJS();
>>> +
>>> +$(function() {
>>> +    pakfire.documentReady();
>>> +});
>>> -- 
>>> 2.27.0.windows.1
>>>