diff --git a/apply.pl b/apply.pl index 1bf4075..1dab38c 100644 --- a/apply.pl +++ b/apply.pl @@ -22,6 +22,8 @@ # # +use Fcntl qw( O_WRONLY O_CREAT O_TRUNC ); + sub read_smart_bindery_values() { my( $bind_server, $bind_user, $bind_pass ) = ( '', '', '' ); @@ -594,6 +596,39 @@ sub redirect_msg( $$ ) } +sub smart_log_level_value( $ ) +{ + my $level = $_[0]; + + $level = 'info' unless defined( $level ) && $level ne ''; + $level = lc( $level ); + + return 0 if $level eq 'error'; + return 1 if $level eq 'warning' || $level eq 'warn'; + return 2 if $level eq 'info'; + return 3 if $level eq 'debug'; + return 4 if $level eq 'trace'; + + return 2; +} + +sub smart_current_log_level() +{ + my $level = 'info'; + + $level = $smart_debug_level if defined( $smart_debug_level ) && $smart_debug_level ne ''; + $level = $smart_log_level if defined( $smart_log_level ) && $smart_log_level ne ''; + + return smart_log_level_value( $level ); +} + +sub smart_log_enabled( $ ) +{ + my $level = $_[0]; + + return smart_log_level_value( $level ) <= smart_current_log_level(); +} + sub apply_log_line( $$ ) { my( $level, $msg ) = @_; @@ -601,12 +636,17 @@ sub apply_log_line( $$ ) $level = 'INFO' unless defined( $level ) && $level ne ''; $msg = '' unless defined( $msg ); + return if ! smart_log_enabled( $level ); + my( $sec, $min, $hour, $mday, $mon, $year ) = localtime( time() ); my $ts = sprintf( "%04d-%02d-%02d %02d:%02d:%02d", $year + 1900, $mon + 1, $mday, $hour, $min, $sec ); my $version = defined( $smart_version ) && $smart_version ne '' ? $smart_version : '0.99.pl28'; - my $line = '[' . $ts . '] [' . $level . '] [SMArT ' . $version . '] [apply.pl] ' . $msg . "\n"; + my $level_text = uc( $level ); + $level_text = 'WARNING' if $level_text eq 'WARN'; + + my $line = '[' . $ts . '] [' . $level_text . '] [SMArT ' . $version . '] [apply.pl] ' . $msg . "\n"; if( defined( $bindery_log_fh ) ) { @@ -789,6 +829,17 @@ sub run_bindery_cmd( @ ) if( $rc != 0 ) { my $exit = $rc >> 8; + + # nwbprm is used as cleanup before setting a property again. If the + # property is already absent, nwbprm can return a failure with + # "Could not delete the property". That is harmless here and should not + # abort the whole save operation. + if( defined( $cmd[0] ) && $cmd[0] eq 'nwbprm' && $output =~ /Could not delete the property/i ) + { + apply_log_line( 'INFO', 'bindery command skipped missing property cmd=' . $cmdline . ' output=' . $output ); + return 1; + } + apply_log_line( 'ERROR', 'bindery command failed rc=' . $exit . ' cmd=' . $cmdline . ' output=' . $output ); bindery_error_page( 'Bindery command failed', $cmdline, $output ); return 0; @@ -800,6 +851,144 @@ sub run_bindery_cmd( @ ) return 1; } +sub apply_trace_log( $ ) +{ + apply_log_line( 'TRACE', $_[0] ); +} + +sub apply_debug_log( $ ) +{ + apply_log_line( 'DEBUG', $_[0] ); +} + + +sub run_bindery_pipe( $$ ) +{ + my( $cmd, $payload ) = @_; + + my $eval_error = ''; + my $result = eval + { + $cmd = '' unless defined( $cmd ); + $payload = '' unless defined( $payload ); + + apply_log_line( 'INFO', 'bindery pipe command: ' . $cmd ); + + my $log_payload = $payload; + $log_payload =~ s/\r/\\r/g; + $log_payload =~ s/\n/\\n/g; + $log_payload = substr( $log_payload, 0, 500 ) . '...' if length( $log_payload ) > 500; + apply_trace_log( 'bindery pipe payload=' . $log_payload ); + + apply_trace_log( 'bindery pipe trace: entered run_bindery_pipe' ); + + my $tmpdir = '/run/mars-nwe-webui'; + $tmpdir = '/tmp' if ! -d $tmpdir || ! -w $tmpdir; + + my $tmp = $tmpdir . '/smart-bindery-' . $$ . '-' . int( rand( 1000000 ) ) . '.in'; + apply_trace_log( 'bindery pipe trace: temp file ' . $tmp ); + + my $tfh; + if( ! sysopen( $tfh, $tmp, O_WRONLY | O_CREAT | O_TRUNC, 0600 ) ) + { + my $output = 'could not create temporary input file ' . $tmp . ': ' . $!; + apply_log_line( 'ERROR', 'bindery pipe command failed cmd=' . $cmd . ' output=' . $output ); + bindery_error_page( 'Bindery command failed', $cmd, $output ); + return 0; + } + + apply_trace_log( 'bindery pipe trace: temp file opened' ); + apply_trace_log( 'bindery pipe trace: writing payload via syswrite length=' . length( $payload ) ); + + my $offset = 0; + my $len = length( $payload ); + + while( $offset < $len ) + { + my $written = syswrite( $tfh, $payload, $len - $offset, $offset ); + + if( ! defined( $written ) ) + { + my $output = 'could not write temporary input file ' . $tmp . ': ' . $!; + close( $tfh ); + unlink( $tmp ); + apply_log_line( 'ERROR', 'bindery pipe command failed cmd=' . $cmd . ' output=' . $output ); + bindery_error_page( 'Bindery command failed', $cmd, $output ); + return 0; + } + + if( $written == 0 ) + { + my $output = 'could not write temporary input file ' . $tmp . ': zero bytes written'; + close( $tfh ); + unlink( $tmp ); + apply_log_line( 'ERROR', 'bindery pipe command failed cmd=' . $cmd . ' output=' . $output ); + bindery_error_page( 'Bindery command failed', $cmd, $output ); + return 0; + } + + $offset += $written; + } + + apply_trace_log( 'bindery pipe trace: payload written bytes=' . $offset ); + + if( ! close( $tfh ) ) + { + my $output = 'could not close temporary input file ' . $tmp . ': ' . $!; + unlink( $tmp ); + apply_log_line( 'ERROR', 'bindery pipe command failed cmd=' . $cmd . ' output=' . $output ); + bindery_error_page( 'Bindery command failed', $cmd, $output ); + return 0; + } + + apply_trace_log( 'bindery pipe trace: temp file closed' ); + + my $shell_cmd = $cmd . ' < ' . apply_shell_quote( $tmp ); + apply_trace_log( 'bindery pipe shell command: ' . $shell_cmd ); + + my $output = `$shell_cmd 2>&1`; + my $rc = $?; + + apply_trace_log( 'bindery pipe trace: shell command returned rc=' . ( $rc >> 8 ) ); + + unlink( $tmp ); + apply_trace_log( 'bindery pipe trace: temp file removed' ); + + $output = '' unless defined( $output ); + $output =~ s/\r//g; + + if( $rc != 0 ) + { + my $exit = $rc >> 8; + apply_log_line( 'ERROR', 'bindery pipe command failed rc=' . $exit . ' cmd=' . $cmd . ' output=' . $output ); + bindery_error_page( 'Bindery command failed', $cmd, $output ); + return 0; + } + + $bindery_cmd_ok_count++; + apply_log_line( 'INFO', 'bindery pipe command ok cmd=' . $cmd . ( $output ne '' ? ' output=' . $output : '' ) ); + + return 1; + }; + + if( ! $result ) + { + $eval_error = $@ if defined( $@ ) && $@ ne ''; + + if( $eval_error ne '' ) + { + apply_log_line( 'ERROR', 'bindery pipe command died cmd=' . $cmd . ' error=' . $eval_error ); + bindery_error_page( 'Bindery command failed', $cmd, 'internal error while running bindery pipe command: ' . $eval_error ); + return 0; + } + + return 0; + } + + return 1; +} + + sub run_shell_bindery_cmd( $ ) { my $cmd = $_[0]; @@ -1001,7 +1190,7 @@ sub handle_request() { apply_log_line( 'INFO', 'UNIX_USER removal skipped for existing user ' . $c[2] ); } -return( 1 ) if ! run_bindery_cmd( 'nwbprm', '-S', $server, '-t', '1', '-o', $c[2], '-p', 'IDENTIFICATION' ); + return( 1 ) if ! run_bindery_cmd( 'nwbprm', '-S', $server, '-t', '1', '-o', $c[2], '-p', 'IDENTIFICATION' ); return( 1 ) if ! run_bindery_cmd( 'nwbprm', '-S', $server, '-t', '1', '-o', $c[2], '-p', 'GROUPS_I\'M_IN' ); return( 1 ) if ! run_bindery_cmd( 'nwbprm', '-S', $server, '-t', '1', '-o', $c[2], '-p', 'SECURITY_EQUALS' ); } @@ -1017,14 +1206,13 @@ return( 1 ) if ! run_bindery_cmd( 'nwbprm', '-S', $server, '-t', '1', '-o', $c[2 } else { - if( $should_update_unix_user ) + if( $should_update_unix_user ) { write_property_string( $c[2], 1, 'UNIX_USER', 0, 30, $p{unix_user} ); } write_property_string( $c[2], 1, 'IDENTIFICATION', 0, 30, $p{fullname} ); - open( FILE, '|' . 'nwbpset -S ' . $server ); - print FILE < /dev/null' ); } - close( FILE ); + return( 1 ) if ! run_bindery_pipe( 'nwbpset -S ' . $server, $bindery_pipe_payload ); - open( FILE, '|' . 'nwbpset -S ' . $server ); - print FILE <