Skip to content

Commit

Permalink
Merge branch '5.0/add-scrip-logging' into 5.0-trunk
Browse files Browse the repository at this point in the history
  • Loading branch information
@sunnavy
sunnavy committed Sep 8, 2023
2 parents 4157646 + b69fbc3 commit bd006e6
Show file tree
Hide file tree
Showing 10 changed files with 509 additions and 19 deletions.
30 changes: 29 additions & 1 deletion etc/RT_Config.pm.in
View file
Original file line number Diff line number Diff line change
Expand Up @@ -378,6 +378,34 @@ See the L<Log::Dispatch::Syslog> documentation for more information.

Set(@LogToSyslogConf, ());

=item C<$LogScripsForUser>

Enables logging for each Scrip, and log output can then be found in the
Scrip Admin web interface. Log output is shown for the most recent run
of each scrip.

Accepts a hashref with username and log level. Output is generated only
when that user performs an action that runs the scrip. Log levels are
the same as for other RT logging. For example:

Set($LogScripsForUser, { 'Username1' => 'debug', 'Username2' => 'warning' });

This allows you to enable debug logging just for yourself as you test
a new scrip.

If you have set the C<LogDir> option it needs to be writeable by the
webserver user for Scrip logging to work.

NOTICE: The Ticket Update page that is used to add a Reply or Comment
will run all relevant Scrips in a dry run mode that executes the
Scrip Condition and Scrip Prepare code. This means log files might be
created just by loading the Ticket Update page if Scrip logging is
enabled.

=cut

Set($LogScripsForUser, {});

=back


Expand Down Expand Up @@ -3961,7 +3989,7 @@ Set(%AdminSearchResultFormat,
Scrips =>
q{'<a href="__WebPath__/Admin/Scrips/Modify.html?id=__id____From__">__id__</a>/TITLE:#'}
.q{,'<a href="__WebPath__/Admin/Scrips/Modify.html?id=__id____From__">__Description__</a>/TITLE:Description'}
.q{,__Condition__, __Action__, __Template__, __Disabled__},
.q{,__Condition__, __Action__, __Template__, __Disabled__,__HasLogs__},

Templates =>
q{'<a href="__WebPath__/__WebRequestPathDir__/Template.html?Queue=__QueueId__&Template=__id__">__id__</a>/TITLE:#'}
Expand Down
144 changes: 126 additions & 18 deletions lib/RT.pm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -229,6 +229,24 @@ Create the Logger object and set up signal handlers.
=cut

my $simple_cb = sub {
# if this code throw any warnings we can get segfault
no warnings;
my %p = @_;

# skip Log::* stack frames
my $frame = 0;
$frame++ while caller($frame) && caller($frame) =~ /^Log::/;
my ($package, $filename, $line) = caller($frame);

# Encode to bytes, so we don't send wide characters
$p{message} = Encode::encode("UTF-8", $p{message});

$p{'message'} =~ s/(?:\r*\n)+$//;
return "[$$] [". gmtime(time) ."] [". $p{'level'} ."]: "
. $p{'message'} ." ($filename:$line)\n";
};

sub InitLogging {

# We have to set the record separator ($, man perlvar)
Expand Down Expand Up @@ -266,24 +284,6 @@ sub InitLogging {
$stack_from_level = 99; # don't log
}

my $simple_cb = sub {
# if this code throw any warning we can get segfault
no warnings;
my %p = @_;

# skip Log::* stack frames
my $frame = 0;
$frame++ while caller($frame) && caller($frame) =~ /^Log::/;
my ($package, $filename, $line) = caller($frame);

# Encode to bytes, so we don't send wide characters
$p{message} = Encode::encode("UTF-8", $p{message});

$p{'message'} =~ s/(?:\r*\n)+$//;
return "[$$] [". gmtime(time) ."] [". $p{'level'} ."]: "
. $p{'message'} ." ($filename:$line)\n";
};

my $syslog_cb = sub {
# if this code throw any warning we can get segfault
no warnings;
Expand Down Expand Up @@ -412,6 +412,114 @@ sub InitSignalHandlers {
};
}

=head2 AddFileLogger
RT->AddFileLogger(
filename => 'filename.log', # will be created in C<$LogDir>
log_level => 'warn', # Log::Dispatch log level
);
Add a new file logger at runtime. Used to add short lived file loggers
that are currently only used for logging Scrip errors.
Note that the log file will be opened in write mode and will overwrite
an existing file with the same name.
To remove the file logger use C<RemoveFileLogger>.
=cut

sub AddFileLogger {
my $self = shift;
my %args = (
log_level => 'warn',
@_
);

return unless $args{filename};

# return if there is a already a logger with this name
if ( $RT::Logger->output( $args{filename} ) ) {
RT->Logger->error("File Logger '$args{filename}' already exists.");
return;
}

my $logdir = RT->Config->Get('LogDir') || File::Spec->catdir( $VarPath, 'log' );
$logdir = File::Spec->catdir( $logdir, 'scrips' );
my $filename = File::Spec->catfile( $logdir, $args{filename} );

unless ( -e $logdir ) {
require File::Path;
File::Path::make_path($logdir);
}
unless ( -d $logdir && -w $logdir ) {
RT->Logger->error("Log dir '$logdir' is not writeable.");
return;
}

require Log::Dispatch::File;
$RT::Logger->add(
Log::Dispatch::File->new(
name => $args{filename},
min_level => $args{log_level},
filename => $filename,
mode => 'write',
callbacks => [ $simple_cb ],
)
);

return 1;
}

=head2 RemoveFileLogger
RT->RemoveFileLogger(
'filename.log',
'an optional final log message',
);
Remove a file logger that was added at runtime. Used to remove file
loggers added with C<AddFileLogger>.
Acccepts an optional second argument to add a final log message that is
only appended to the log file if the log file is not empty.
If the log file is empty it is deleted to avoid empty log files in the
log directory.
=cut

sub RemoveFileLogger {
my $self = shift;
my $filename = shift;
my $final_log = shift;

return unless $filename;

# return if there is not a logger with this name
return unless $RT::Logger->output($filename);

$RT::Logger->remove($filename);

# if the log file is empty delete it
my $logdir = RT->Config->Get('LogDir') || File::Spec->catdir( $VarPath, 'log' );
$logdir = File::Spec->catdir( $logdir, 'scrips' );
$filename = File::Spec->catfile( $logdir, $filename );

if ( -z $filename ) {
unlink $filename;
}
elsif ( -s $filename && $final_log ) {
# add a final message with log details
if ( open my $fh, '>>', $filename ) {
print $fh $final_log;
close $fh;
}
else {
RT->Logger->error("Cannot write to '$filename': $!");
}
}
}

sub CheckPerlRequirements {
eval {require 5.010_001};
Expand Down
3 changes: 3 additions & 0 deletions lib/RT/Config.pm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2245,6 +2245,9 @@ our %META;
LogToSyslogConf => {
Immutable => 1,
},
LogScripsForUser => {
Type => 'HASH',
},
ShowMobileSite => {
Widget => '/Widgets/Form/Boolean',
},
Expand Down
1 change: 1 addition & 0 deletions lib/RT/Interface/Web/MenuBuilder.pm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1571,6 +1571,7 @@ sub _BuildAdminMenu {

$page->child( basics => title => loc('Basics') => path => "/Admin/Scrips/Modify.html?id=" . $id . $from_query_param );
$page->child( 'applies-to' => title => loc('Applies to'), path => "/Admin/Scrips/Objects.html?id=" . $id . $from_query_param );
$page->child( 'logging' => title => loc('Log Output'), path => "/Admin/Scrips/Logging.html?id=" . $id . $from_query_param );
}
elsif ( $request_path =~ m{^/Admin/Scrips/(index\.html)?$} ) {
HTML::Mason::Commands::PageMenu->child( select => title => loc('Select') => path => "/Admin/Scrips/" );
Expand Down
74 changes: 74 additions & 0 deletions lib/RT/Scrip.pm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -584,6 +584,9 @@ sub IsApplicable {
return (undef);
}
my $ConditionObj = $self->ConditionObj;

$self->_AddFileLogger('IsApplicable');

foreach my $TransactionObj ( @Transactions ) {
# in TxnBatch stage we can select scrips that are not applicable to all txns
my $txn_type = $TransactionObj->Type;
Expand All @@ -602,6 +605,7 @@ sub IsApplicable {
}
}
};
$self->_RemoveFileLogger('IsApplicable');

if ($@) {
$RT::Logger->error( "Scrip IsApplicable " . $self->Id . " died. - " . $@ );
Expand Down Expand Up @@ -635,8 +639,12 @@ sub Prepare {
TemplateObj => $self->TemplateObj( $args{'TicketObj'}->Queue ),
);

$self->_AddFileLogger('Prepare');

$return = $self->ActionObj->Prepare();
};
$self->_RemoveFileLogger('Prepare');

if ($@) {
$RT::Logger->error( "Scrip Prepare " . $self->Id . " died. - " . $@ );
return (undef);
Expand All @@ -662,8 +670,11 @@ sub Commit {

my $return;
eval {
$self->_AddFileLogger('Commit');

$return = $self->ActionObj->Commit();
};
$self->_RemoveFileLogger('Commit');

#Searchbuilder caching isn't perfectly coherent. got to reload the ticket object, since it
# may have changed
Expand All @@ -680,9 +691,72 @@ sub Commit {
return ($return);
}

=head2 _LoggerFilename
Helper method to generate the filename for a file logger for Scrip
logging.
=cut

sub _LoggerFilename {
my $self = shift;
my $mode = shift;

return 'scrip-' . $self->id . "-$mode.log";
};

=head2 _AddFileLogger
Checks the C<LogScripsForUser> config option to determine if Scrip
logging is enabled for the current user and if so it calls
RT::AddFileLogger to add a short lived file logger used for Scrip
logging.
=cut

sub _AddFileLogger {
my $self = shift;
my $mode = shift;

my $config = RT->Config->Get('LogScripsForUser');
my $current_user = $HTML::Mason::Commands::session{CurrentUser} || $self->CurrentUser;

return unless $config;
return unless $current_user;
return unless $config->{ $current_user->Name };

RT->AddFileLogger(
filename => $self->_LoggerFilename($mode),
log_level => $config->{ $current_user->Name },
);
}

=head2 _RemoveFileLogger
Calls RT::RemoveFileLogger to remove a short lived file logger used for
Scrip logging.
Passes RT::RemoveFileLogger a final log message that includes the date
the log was created and the user it was created for.
=cut

sub _RemoveFileLogger {
my $self = shift;
my $mode = shift;

my $config = RT->Config->Get('LogScripsForUser');
my $current_user = $HTML::Mason::Commands::session{CurrentUser} || $self->CurrentUser;

return unless $config;
return unless $current_user;
return unless $config->{ $current_user->Name };

my $log_level = $config->{ $current_user->Name };
my $final_log = "\nLog created on " . gmtime(time) . " for " . $current_user->Name . " at log level $log_level\n";

RT->RemoveFileLogger( $self->_LoggerFilename($mode), $final_log );
}

# does an acl check and then passes off the call
sub _Set {
Expand Down
40 changes: 40 additions & 0 deletions share/html/Admin/Scrips/Elements/EditCustomCode
View file
Original file line number Diff line number Diff line change
Expand Up @@ -65,6 +65,18 @@
<textarea spellcheck="false" cols="80" class="form-control" rows="<% $lines %>" name="<% $method %>"><% $code %></textarea>
</div>
</div>

% if ( $errors{$method} ) {
<div class="form-row">
<div class="label col-2 labeltop scrip-log">
<% loc('Log Output') %>:
</div>
<div class="value col-9">
<textarea spellcheck="false" cols="80" rows="5" class="form-control" readonly><% $errors{$method} %></textarea>
</div>
</div>
% }

% }

</&>
Expand All @@ -79,4 +91,32 @@ my @list = (
);

my $min_lines = 10;

my %errors = (
'CustomIsApplicableCode' => '',
'CustomPrepareCode' => '',
'CustomCommitCode' => '',
);

if ( $Scrip->id ) {
my @stages = ();
if ( $Scrip->ConditionObj->ExecModule eq 'UserDefined' ) {
push @stages, 'IsApplicable';
}
if ( $Scrip->ActionObj->ExecModule eq 'UserDefined' ) {
push @stages, 'Prepare', 'Commit';
}

my $logdir = RT->Config->Get('LogDir') || File::Spec->catdir( $RT::VarPath, 'log' );
$logdir = File::Spec->catdir( $logdir, 'scrips' );
foreach my $stage ( @stages ) {
my $filename = File::Spec->catfile( $logdir, 'scrip-' . $Scrip->id . '-' . $stage . '.log' );
if ( -s $filename ) {
local $/;
open ( my $f, '<:encoding(UTF-8)', $filename )
or die "Cannot open initialdata file '$filename' for read: $@";
$errors{ 'Custom' . $stage . 'Code' } = <$f>;
}
}
}
</%INIT>
Loading

0 comments on commit bd006e6

Please sign in to comment.