* new version of function daemon_log

* extended meaning of daemon_log function parameter level
* new command line option -d (debugging gosa-si parts)

git-svn-id: https://oss.gonicus.de/repositories/gosa/trunk@13692 594d385d-05f5-0310-b6e9-bd551577e9d8

diff --git a/gosa-si/gosa-si-server b/gosa-si/gosa-si-server
index e1fa9767f4b3863c7bdd6a3f318230464c7720c6..d391e2de71a3bd1a3f384d333094e4095ff5265a 100755 (executable)
--- a/gosa-si/gosa-si-server
+++ b/gosa-si/gosa-si-server
@@ -63,7 +63,7 @@ my $db_module = "DBsqlite";
 no strict "refs";
 require ("GOSA/".$db_module.".pm");
 ("GOSA/".$db_module)->import;
-daemon_log("0 INFO: importing database module '$db_module'", 1);
+#daemon_log("0 INFO: importing database module '$db_module'", 1);
 }
 
 my $modules_path = "/usr/lib/gosa-si/modules";
@@ -76,6 +76,8 @@ my ($gosa_server, $job_queue_timeout, $job_queue_loop_delay);
 my ($messaging_db_loop_delay);
 my ($procid, $pid);
 my $arp_fifo;
+my $debug_parts = 0;
+my $debug_parts_bitstring;
 my ($xml);
 my $sources_list;
 my $max_clients;
@@ -220,6 +222,8 @@ our $opsi_url;
 # of this, the user is deleted from login_users_db
 our $logged_in_user_date_of_expiry = 600;
 
+# List of month names, used in function daemon_log
+my @monthnames = ("Jan", "Feb", "Mar", "Apr", "May", "Jun", "Jul", "Aug", "Sep", "Oct", "Nov", "Dec");
 
 %cfg_defaults = (
 "general" => {
@@ -295,13 +299,23 @@ our $logged_in_user_date_of_expiry = 600;
 #===============================================================================
 sub usage {
     print STDERR << "EOF" ;
-usage: $prg [-hvf] [-c config]
+usage: $prg [-hvf] [-c config] [-d number]
 
            -h        : this (help) message
            -c <file> : config file
            -f        : foreground, process will not be forked to background
            -v        : be verbose (multiple to increase verbosity)
+                              'v': error logs
+                            'vvv': warning plus error logs                                             
+                          'vvvvv': info plus warning logs
+                        'vvvvvvv': debug plus info logs
            -no-arp   : starts $prg without connection to arp module
+           -d <int>  : if verbose level is higher than 7x 'v' specified parts can be debugged
+                           1 : receiving messages
+                           2 : sending messages
+                           4 : encrypting/decrypting messages
+                           8 : verification if a message complies gosa-si requirements
+                          16 :
  
 EOF
     print "\n" ;
@@ -317,48 +331,66 @@ EOF
 #  DESCRIPTION:  function for logging
 #===============================================================================
 sub daemon_log {
-    # log into log_file
     my( $msg, $level ) = @_;
-    if(not defined $msg) { return }
-    if(not defined $level) { $level = 1 }
-               if($level > $verbose) { return }
-    if(defined $log_file){
-        my $open_log_fh = sysopen(LOG_HANDLE, $log_file, O_WRONLY | O_CREAT | O_APPEND , 0440);
-        if(not $open_log_fh) {
-            print STDERR "cannot open $log_file: $!";
-            return;
-        }
-        # check owner and group of log_file and update settings if necessary
-        my ($dev, $ino, $mode, $nlink, $uid, $gid, $rdev, $size, $atime, $mtime, $ctime, $blksize, $blocks) = stat($log_file);
-        if((not $uid eq $root_uid) || (not $gid eq $adm_gid)) {
-            chown($root_uid, $adm_gid, $log_file);
+    if (not defined $msg) { return }
+    if (not defined $level) { $level = 1 }
+       my $to_be_logged = 0;
+
+       # Write log line if line level is lower than verbosity given in commandline
+       if ($level <= $verbose) 
+       { 
+               $to_be_logged = 1 ;
+       }
+
+       # Write if debug flag is set and bitstring matches
+       if ($debug_parts > 0)
+       {
+               my $tmp_level = ($level - 10 >= 0) ? $level - 10 : 0 ;
+               my $tmp_level_bitstring = unpack("B32", pack("N", $tmp_level));
+               if (int($debug_parts_bitstring & $tmp_level_bitstring)) 
+               {
+                       $to_be_logged = 1;
                }
+       }
 
-        chomp($msg);
-        #$msg =~s/\n//g;   # no newlines are allowed in log messages, this is important for later log parsing
-        if($level <= $verbose){
-            my ($seconds, $minutes, $hours, $monthday, $month,
-                    $year, $weekday, $yearday, $sommertime) = localtime(time);
-            $hours = $hours < 10 ? $hours = "0".$hours : $hours;
-            $minutes = $minutes < 10 ? $minutes = "0".$minutes : $minutes;
-            $seconds = $seconds < 10 ? $seconds = "0".$seconds : $seconds;
-            my @monthnames = ("Jan", "Feb", "Mar", "Apr", "May", "Jun", "Jul", "Aug", "Sep", "Oct", "Nov", "Dec");
-            $month = $monthnames[$month];
-            $monthday = $monthday < 10 ? $monthday = "0".$monthday : $monthday;
-            $year+=1900;
-            my $name = $prg;
-
-            my $log_msg = "$month $monthday $hours:$minutes:$seconds $name $msg\n";
+       if ($to_be_logged) 
+       {
+               if(defined $log_file){
+                       my $open_log_fh = sysopen(LOG_HANDLE, $log_file, O_WRONLY | O_CREAT | O_APPEND , 0440);
+                       if(not $open_log_fh) {
+                               print STDERR "cannot open $log_file: $!";
+                               return;
+                       }
+                       # Check owner and group of log_file and update settings if necessary
+                       my ($dev, $ino, $mode, $nlink, $uid, $gid, $rdev, $size, $atime, $mtime, $ctime, $blksize, $blocks) = stat($log_file);
+                       if((not $uid eq $root_uid) || (not $gid eq $adm_gid)) {
+                               chown($root_uid, $adm_gid, $log_file);
+                       }
+
+                       # Prepare time string for log message
+                       my ($seconds,$minutes,$hours,$monthday,$month,$year,$weekday,$yearday,$sommertime) = localtime(time);
+                       $hours = $hours < 10 ? $hours = "0".$hours : $hours;
+                       $minutes = $minutes < 10 ? $minutes = "0".$minutes : $minutes;
+                       $seconds = $seconds < 10 ? $seconds = "0".$seconds : $seconds;
+                       $month = $monthnames[$month];
+                       $monthday = $monthday < 10 ? $monthday = "0".$monthday : $monthday;
+                       $year+=1900;
+
+                       
+                       # Build log message and write it to log file and commandline
+                       chomp($msg);
+                       my $log_msg = "$month $monthday $hours:$minutes:$seconds $prg $msg\n";
                        flock(LOG_HANDLE, LOCK_EX);
                        seek(LOG_HANDLE, 0, 2);
-            print LOG_HANDLE $log_msg;
+                       print LOG_HANDLE $log_msg;
                        flock(LOG_HANDLE, LOCK_UN);
-            if( $foreground ) { 
-                print STDERR $log_msg;
-            }
-        }
-        close( LOG_HANDLE );
-    }
+                       if( $foreground ) 
+                       { 
+                               print STDERR $log_msg;
+                       }
+                       close( LOG_HANDLE );
+               }
+       }
 }
 
 
@@ -369,19 +401,35 @@ sub daemon_log {
 #  DESCRIPTION:  validates commandline parameter
 #===============================================================================
 sub check_cmdline_param () {
-    my $err_config;
     my $err_counter = 0;
+
+       # Check configuration file
        if(not defined($cfg_file)) {
                $cfg_file = "/etc/gosa-si/server.conf";
                if(! -r $cfg_file) {
-                       $err_config = "please specify a config file";
-                       $err_counter += 1;
+                       print STDERR "Please specify a config file.\n";
+                       $err_counter++;
                }
     }
-    if( $err_counter > 0 ) {
+
+       # Prepare identification which gosa-si parts should be debugged and which not
+       if (defined $debug_parts) 
+       {
+               if ($debug_parts =~ /^\d+$/)
+               {
+                       $debug_parts_bitstring = unpack("B32", pack("N", $debug_parts));
+               }
+               else
+               {
+                       print STDERR "Value '$debug_parts' invalid for option d (number expected)\n";
+                       $err_counter++;
+               }
+       }
+
+       # Exit if an error occour
+    if( $err_counter > 0 ) 
+       {
         &usage( "", 1 );
-        if( defined( $err_config)) { print STDERR "$err_config\n"}
-        print STDERR "\n";
         exit( -1 );
     }
 }
@@ -537,7 +585,7 @@ sub check_key_and_xml_validity {
 
         if ($msg =~ /<xml>/i){
             $msg =~ s/\s+/ /g;  # just for better daemon_log
-            daemon_log("$session_id DEBUG: decrypted_msg: \n$msg", 9);
+            daemon_log("$session_id DEBUG: decrypted_msg: \n$msg", 18);
             $msg_hash = $xml->XMLin($msg, ForceArray=>1);
 
             ##############
@@ -661,27 +709,27 @@ sub input_from_known_server {
             next;
         }
         my $host_key = $hit->{hostkey};
-        #daemon_log("$session_id DEBUG: input_from_known_server: host_name: $host_name", 7);
-        #daemon_log("$session_id DEBUG: input_from_known_server: host_key: $host_key", 7);
+        daemon_log("$session_id DEBUG: input_from_known_server: host_name: $host_name", 14);
+        daemon_log("$session_id DEBUG: input_from_known_server: host_key: $host_key", 14);
 
         # check if module can open msg envelope with module key
         my ($tmp_msg, $tmp_msg_hash) = &check_key_and_xml_validity($input, $host_key, $session_id);
         if( (!$tmp_msg) || (!$tmp_msg_hash) ) {
-            daemon_log("$session_id DEBUG: input_from_known_server: deciphering raise error", 7);
-            daemon_log("$@", 8);
+            daemon_log("$session_id DEBUG: input_from_known_server: deciphering raise error", 14);
+            daemon_log("$@", 14);
             next;
         }
         else {
             $msg = $tmp_msg;
             $msg_hash = $tmp_msg_hash;
             $module = "ServerPackages";
-            daemon_log("$session_id DEBUG: check_key_and_xml_validity... ok", 7);
+            daemon_log("$session_id DEBUG: check_key_and_xml_validity... ok", 14);
             last;
         }
     }
 
     if( (!$msg) || (!$msg_hash) || (!$module) ) {
-        #daemon_log("$session_id DEBUG: Incoming message is not from a known server", 7);
+        daemon_log("$session_id DEBUG: Incoming message is not from a known server", 14);
     }
   
     return ($msg, $msg_hash, $module);
@@ -700,25 +748,25 @@ sub input_from_known_client {
                 next;
                }
         my $host_key = $hit->{hostkey};
-        #&daemon_log("$session_id DEBUG: input_from_known_client: host_name: $host_name", 7);
-        #&daemon_log("$session_id DEBUG: input_from_known_client: host_key: $host_key", 7);
+        &daemon_log("$session_id DEBUG: input_from_known_client: host_name: $host_name", 14);
+        &daemon_log("$session_id DEBUG: input_from_known_client: host_key: $host_key", 14);
 
         # check if module can open msg envelope with module key
         ($msg, $msg_hash) = &check_key_and_xml_validity($input, $host_key, $session_id);
 
         if( (!$msg) || (!$msg_hash) ) {
-            &daemon_log("$session_id DEGUG: input_from_known_client: deciphering raise error", 7);
+            &daemon_log("$session_id DEGUG: input_from_known_client: deciphering raise error", 14);
             next;
         }
         else {
             $module = "ClientPackages";
-            daemon_log("$session_id DEBUG: check_key_and_xml_validity... ok", 7);
+            daemon_log("$session_id DEBUG: check_key_and_xml_validity... ok", 14);
             last;
         }
     }
 
     if( (!$msg) || (!$msg_hash) || (!$module) ) {
-        #&daemon_log("$session_id DEBUG: Incoming message is not from a known client", 7);
+        &daemon_log("$session_id DEBUG: Incoming message is not from a known client", 14);
     }
 
     return ($msg, $msg_hash, $module);
@@ -744,7 +792,7 @@ sub input_from_unknown_host {
                        daemon_log("$session_id ERROR: no key specified in config file for $mod", 1);
                        next;
                }
-               #daemon_log("$session_id DEBUG: $mod: $module_key", 7);
+               daemon_log("$session_id DEBUG: $mod: $module_key", 14);
 
                # check if module can open msg envelope with module key
                ($msg, $msg_hash) = &check_key_and_xml_validity($input, $module_key, $session_id);
@@ -752,13 +800,13 @@ sub input_from_unknown_host {
                        next;
                } else {
                        $module = $mod;
-            daemon_log("$session_id DEBUG: check_key_and_xml_validity... ok", 7);
+            daemon_log("$session_id DEBUG: check_key_and_xml_validity... ok", 18);
                        last;
                }
        }
 
        if( (!$msg) || (!$msg_hash) || (!$module)) {
-               #daemon_log("$session_id DEBUG: Incoming message is not from an unknown host", 7);
+               daemon_log("$session_id DEBUG: Incoming message is not from an unknown host", 14);
        }
 
        return ($msg, $msg_hash, $module);
@@ -907,7 +955,7 @@ sub send_msg_to_target {
         # send xml msg
         print $socket $crypted_msg.";$own_source_address\n";
         daemon_log("$session_id INFO: send ".$header."msg to $address", 5);
-        daemon_log("$session_id DEBUG: message:\n$msg", 9);
+        daemon_log("$session_id DEBUG: message:\n$msg", 12);
         
     }
 
@@ -1114,7 +1162,7 @@ sub msg_to_decrypt {
                        daemon_log("$session_id ERROR: incoming message from host '$foreign_host' cannot be understood. Processing aborted: $tmp_next_msg", 1);
                }
 
-               $error++;
+               $error++
        }
 
 
@@ -1157,7 +1205,7 @@ sub msg_to_decrypt {
                if (not $done) {
                        if ($target eq "GOSA" && $source eq "GOSA") {
                                $done = 1;                    
-                               &daemon_log("$session_id DEBUG: target and source is 'GOSA' -> process here", 7);
+                               &daemon_log("$session_id DEBUG: target and source is 'GOSA' -> process '$header' here", 11);
                        }
                }
 
@@ -1169,7 +1217,7 @@ sub msg_to_decrypt {
                                if ($source eq "GOSA") {
                                        $msg =~ s/<\/xml>/<forward_to_gosa>$local_address,$session_id<\/forward_to_gosa><\/xml>/;
                                }
-                               &daemon_log("$session_id DEBUG: target is own address without forward_to_gosa-tag -> process here", 7);
+                               &daemon_log("$session_id DEBUG: target is own address without forward_to_gosa-tag -> process '$header' here", 11);
                        }
                }
 
@@ -1182,7 +1230,7 @@ sub msg_to_decrypt {
                                my ($gosa_at, $gosa_session_id) = split(/,/, $forward_to_gosa);
                                if ($gosa_at ne $local_address) {
                                        $done = 1;
-                                       &daemon_log("$session_id DEBUG: target is own address with forward_to_gosa-tag not pointing to myself -> process here", 7); 
+                                       &daemon_log("$session_id DEBUG: target is own address with forward_to_gosa-tag not pointing to myself -> process '$header' here", 11); 
                                }
                        }
                }
@@ -1203,7 +1251,7 @@ sub msg_to_decrypt {
                                {
                                        $msg =~ s/<target>\S*<\/target>/<target>$hostname<\/target>/;
                                        $done = 1;
-                                       &daemon_log("$session_id DEBUG: Target is client address with processing function within a plugin -> process here", 7);
+                                       &daemon_log("$session_id DEBUG: Target is client address with processing function within a plugin -> process '$header' here", 11);
                                }
                        }
                }
@@ -1213,7 +1261,7 @@ sub msg_to_decrypt {
                if ((not $done) && ($header =~ /job_/))
                {
                        $done = 1;
-                       &daemon_log("$session_id DEBUG: Header has a 'job_' prefix. Put it into job queue. -> process here", 7);
+                       &daemon_log("$session_id DEBUG: Header has a 'job_' prefix. Put it into job queue. -> process '$header' here", 11);
                }
 
                # if message should be processed here -> add message to incoming_db
@@ -1251,10 +1299,10 @@ sub msg_to_decrypt {
                                        if(exists $heap->{'client'}) {
                                                $msg = &encrypt_msg($msg, $GosaPackages_key);
                                                $heap->{'client'}->put($msg);
-                                               &daemon_log("$session_id INFO: incoming '$header' message forwarded to GOsa", 5); 
+                                               &daemon_log("$session_id DEBUG: incoming '$header' message forwarded to GOsa", 11); 
                                        }
                                        $done = 1;
-                                       &daemon_log("$session_id DEBUG: target is own address with forward_to_gosa-tag pointing at myself -> forward to gosa", 7);
+                                       &daemon_log("$session_id DEBUG: target is own address with forward_to_gosa-tag pointing at myself -> forward '$header' to gosa", 11);
                                }
                        }
 
@@ -1267,7 +1315,7 @@ sub msg_to_decrypt {
                        if (keys(%$res) > 0) 
                        {
                                $done = 1; 
-                               &daemon_log("$session_id DEBUG: target is a client address in known_clients -> forward to client", 7);
+                               &daemon_log("$session_id DEBUG: target is a client address in known_clients -> forward '$header' to client", 11);
                                my $hostkey = $res->{1}->{'hostkey'};
                                my $hostname = $res->{1}->{'hostname'};
                                $msg =~ s/<target>\S*<\/target>/<target>$hostname<\/target>/;
@@ -1307,7 +1355,7 @@ sub msg_to_decrypt {
                                        }
                                }
                                $done = 1;
-                               &daemon_log("$session_id DEBUG: target is a client address in foreign_clients -> forward to registration server", 7);
+                               &daemon_log("$session_id DEBUG: target is a client address in foreign_clients -> forward '$header' to registration server", 11);
                        } else {
                                $not_found_in_foreign_clients_db = 1;
                        }
@@ -1328,7 +1376,7 @@ sub msg_to_decrypt {
 
                                &send_msg_to_target($msg, $target, $hostkey, $header, $session_id);
                                $done = 1;
-                               &daemon_log("$session_id DEBUG: target is a server address -> forward to server", 7);
+                               &daemon_log("$session_id DEBUG: target is a server address -> forward '$header' to server", 11);
                        } else {
                                $not_found_in_known_server_db = 1;
                        }
@@ -1339,7 +1387,7 @@ sub msg_to_decrypt {
                if ( $not_found_in_foreign_clients_db 
                        && $not_found_in_known_server_db
                        && $not_found_in_known_clients_db) {
-                       &daemon_log("$session_id DEBUG: target is not in foreign_clients_db, known_server_db or known_clients_db, maybe it is a complete new one -> process here", 7);
+                       &daemon_log("$session_id DEBUG: target is not in foreign_clients_db, known_server_db or known_clients_db, maybe it is a complete new one -> process '$header' here", 11);
             if ($header =~ /^gosa_/ || $header =~ /^job_/) { 
                 $module = "GosaPackages"; 
             }
@@ -3293,7 +3341,8 @@ GetOptions("h|help" => \&usage,
         "f|foreground" => \$foreground,
         "v|verbose+" => \$verbose,
         "no-arp+" => \$no_arp,
-           );
+               "d=s" => \$debug_parts,
+           ) or (&usage("", 1)&&(exit(-1))); 
 
 #  read and set config parameters
 &check_cmdline_param ;
@@ -3580,12 +3629,12 @@ POE::Component::Server::TCP->new(
         my $session_id = $session->ID;
                if ($input =~ /;([\d\.]+:[\d]+)$/) 
                {
-                       &daemon_log("$session_id DEBUG: incoming message from '$1'", 7);
+                       &daemon_log("$session_id DEBUG: incoming message from '$1'", 11);
                }
                else
                {
                        my $remote_ip = $heap->{'remote_ip'};
-                       &daemon_log("$session_id DEBUG: incoming message from '$remote_ip'", 7);
+                       &daemon_log("$session_id DEBUG: incoming message from '$remote_ip'", 11);
                }
                push(@msgs_to_decrypt, $input);
                $kernel->yield("msg_to_decrypt");