Diff for /loncom/metadata_database/parse_activity_log.pl between versions 1.14 and 1.23

version 1.14, 2005/03/31 22:09:40 version 1.23, 2006/03/30 06:57:50
Line 48 Line 48
 # parameter is not set $logthis is set to &nothing, which does what you  # parameter is not set $logthis is set to &nothing, which does what you
 # would expect.  # would expect.
 #  #
   BEGIN {
       eval "use Apache2::compat();";
   };
 use strict;  use strict;
 use DBI;  use DBI;
 use lib '/home/httpd/lib/perl/Apache';  use lib '/home/httpd/lib/perl/Apache';
Line 65  use HTML::TokeParser; Line 67  use HTML::TokeParser;
   
 #  #
 # Determine parameters  # Determine parameters
 my ($help,$course,$domain,$drop_when_done,$srcfile,$logfile,$time_run,$nocleanup,$log,$backup);  my ($help,$course,$domain,$drop_when_done,$srcfile,$logfile,$time_run,$nocleanup,$log,$backup,$xmlfile);
 &Getopt::Long::GetOptions( "course=s"  => \$course,  &Getopt::Long::GetOptions( "course=s"  => \$course,
                            "domain=s"  => \$domain,                             "domain=s"  => \$domain,
                            "backup"    => \$backup,                             "backup"    => \$backup,
                            "help"      => \$help,                             "help"      => \$help,
                            "logfile=s" => \$logfile,                             "logfile=s" => \$logfile,
                            "srcfile=s" => \$srcfile,                             "srcfile=s" => \$srcfile,
                              "justloadxml=s" => \$xmlfile,
                            "timerun"   => \$time_run,                             "timerun"   => \$time_run,
                            "nocleanup" => \$nocleanup,                             "nocleanup" => \$nocleanup,
                            "dropwhendone" => \$drop_when_done,                             "dropwhendone" => \$drop_when_done,
Line 130  if ($log) { Line 133  if ($log) {
     print STDERR "$0: logging to $logfile".$/;      print STDERR "$0: logging to $logfile".$/;
     if (! open(LOGFILE,">$logfile")) {      if (! open(LOGFILE,">$logfile")) {
         warn("Unable to open $logfile for writing.  Run aborted.");          warn("Unable to open $logfile for writing.  Run aborted.");
         exit 5;          &clean_up_and_exit(5);
     } else {      } else {
         $logthis = \&log_to_file;          $logthis = \&log_to_file;
     }      }
Line 143  if ($log) { Line 146  if ($log) {
 my $sourcefilename;   # activity log data  my $sourcefilename;   # activity log data
 my $newfilename;      # $sourcefilename will be renamed to this  my $newfilename;      # $sourcefilename will be renamed to this
 my $error_filename;   # Errors in parsing the activity log will be written here  my $error_filename;   # Errors in parsing the activity log will be written here
   my $chunk_filename;   # where we save data we are not going to write to db
 if ($srcfile) {  if ($srcfile) {
     $sourcefilename = $srcfile;      $sourcefilename = $srcfile;
 } else {  } else {
Line 152  my $sql_filename = $sourcefilename; Line 156  my $sql_filename = $sourcefilename;
 $sql_filename =~ s|[^/]*$|activity.log.sql|;  $sql_filename =~ s|[^/]*$|activity.log.sql|;
 my $gz_sql_filename = $sql_filename.'.gz';  my $gz_sql_filename = $sql_filename.'.gz';
 #  #
   $chunk_filename = $sourcefilename.".unprocessed_chunks";
   #
 my $xml_filename = $sourcefilename;  my $xml_filename = $sourcefilename;
 $xml_filename =~ s|[^/]*$|activity.log.xml|;  
 my $gz_xml_filename = $xml_filename.'.gz';  my $gz_xml_filename = $xml_filename.'.gz';
   if (defined($xmlfile)) {
       $xml_filename = $xmlfile;
       if ($xml_filename =~ /\.gz$/) {
           $gz_xml_filename = $xml_filename;
       } else {
           $gz_xml_filename = $xml_filename.'.gz';
       }
   } else {
       my $xml_filename = $sourcefilename;
       $xml_filename =~ s|[^/]*$|activity.log.xml|;
       $gz_xml_filename = $xml_filename.'.gz';
   }
 #  #
 $error_filename = $sourcefilename;  $error_filename = $sourcefilename;
 $error_filename =~ s|[^/]*$|activity.log.errors|;  $error_filename =~ s|[^/]*$|activity.log.errors|;
Line 163  $logthis->('Beginning logging '.time); Line 180  $logthis->('Beginning logging '.time);
 #  #
 # Wait for a lock on the lockfile to avoid collisions  # Wait for a lock on the lockfile to avoid collisions
 my $lockfilename = $sourcefilename.'.lock';  my $lockfilename = $sourcefilename.'.lock';
 open(LOCKFILE,'>'.$lockfilename);  $newfilename = $sourcefilename.'.processing';
 if (!flock(LOCKFILE,LOCK_EX)) {  if (! defined($xmlfile)) {
     warn("Unable to lock $lockfilename.  Aborting".$/);      open(LOCKFILE,'>'.$lockfilename);
     exit 6;      if (!flock(LOCKFILE,LOCK_EX|LOCK_NB)) {
 }          warn("Unable to lock $lockfilename.  Aborting".$/);
           # don't call clean_up_and_exit another instance is running and
 ##          # we don't want to 'cleanup' their files
 ## There will only be a $newfilename file if a copy of this program is already          exit 6;
 ## running.      }
 my $newfilename = $sourcefilename.'.processing';  
 if (-e $newfilename) {      if (! -e $newfilename && -e $sourcefilename) {
     warn "$newfilename exists";          $logthis->('renaming '.$sourcefilename.' to '.$newfilename);
     $logthis->($newfilename.' exists, so I cannot work on it.');          rename($sourcefilename,$newfilename);
     exit 2;          Copy($newfilename,$newfilename.'.'.time) if ($backup);
 }          $logthis->("renamed $sourcefilename to $newfilename");
       } elsif (! -e $newfilename) {
 if (-e $sourcefilename) {          utime(undef,undef,$newfilename);
     $logthis->('renaming '.$sourcefilename.' to '.$newfilename);      }
     rename($sourcefilename,$newfilename);  
     Copy($newfilename,$newfilename.'.'.time) if ($backup);  
     $logthis->("renamed $sourcefilename to $newfilename");  
 } else {  
     my $command = 'touch '.$newfilename;  
     $logthis->($command);  
     system($command);  
     $logthis->('touch was completed');  
 }  }
   
 close(LOCKFILE);  
   
 ##  ##
 ## Table definitions  ## Table definitions
 ##  ##
Line 299  $logthis->('Connectiong to mysql'); Line 306  $logthis->('Connectiong to mysql');
 if (!&Apache::lonmysql::verify_sql_connection()) {  if (!&Apache::lonmysql::verify_sql_connection()) {
     warn "Unable to connect to MySQL database.";      warn "Unable to connect to MySQL database.";
     $logthis->("Unable to connect to MySQL database.");      $logthis->("Unable to connect to MySQL database.");
     exit 3;      &clean_up_and_exit(3);
 }  }
 $logthis->('SQL connection is up');  $logthis->('SQL connection is up');
   
Line 345  if (-s $gz_sql_filename && ! -s $gz_xml_ Line 352  if (-s $gz_sql_filename && ! -s $gz_xml_
     }          }    
 }  }
   
   if (defined($xmlfile)) {
       &clean_up_and_exit(0);
   }
   
 ##  ##
 ## Ensure the tables we need exist  ## Ensure the tables we need exist
 # create_tables does not complain if the tables already exist  # create_tables does not complain if the tables already exist
Line 352  $logthis->('creating tables'); Line 363  $logthis->('creating tables');
 if (! &create_tables()) {  if (! &create_tables()) {
     warn "Unable to create tables";      warn "Unable to create tables";
     $logthis->('Unable to create tables');      $logthis->('Unable to create tables');
     exit 4;      &clean_up_and_exit(4);
 }  }
   
 ##  ##
Line 373  if (-s $newfilename) { Line 384  if (-s $newfilename) {
     if (! defined($result)) {      if (! defined($result)) {
         # Something went wrong along the way...          # Something went wrong along the way...
         $logthis->('process_courselog returned undef');          $logthis->('process_courselog returned undef');
         exit 5;          &clean_up_and_exit(5);
     } elsif ($result > 0) {      } elsif ($result > 0) {
         $time_this->();          $time_this->();
         $logthis->('process_courselog returned '.$result.' backing up tables');          $logthis->('process_courselog returned '.$result.'.'.$/.
                      'Backing up tables');
         &backup_tables_as_xml($gz_xml_filename,\%tables);          &backup_tables_as_xml($gz_xml_filename,\%tables);
         $time_this->('write backup tables');          $time_this->('write backup tables');
     }      }
Line 400  if ($time_run) { Line 412  if ($time_run) {
     $logthis->(&outputtimes());      $logthis->(&outputtimes());
 }  }
   
 if ($log) {  &clean_up_and_exit(0);
     close LOGFILE;  
 }  
   
 foreach my $file ($lockfilename, $error_filename,$logfile) {  ########################################################
     if (-z $file) {   ########################################################
         unlink($file);   
   sub clean_up_and_exit {
       my ($exit_code) = @_;
       # Close files
       close(LOCKFILE);
       close(LOGFILE);
       # Remove zero length files
       foreach my $file ($lockfilename, $error_filename,$logfile) {
           if (defined($file) && -z $file) { 
               unlink($file); 
           }
     }      }
 }  
   
 exit 0;   # Everything is okay, so end here before it gets worse.      exit $exit_code;
   }
   
 ########################################################  ########################################################
 ########################################################  ########################################################
Line 471  sub process_courselog { Line 491  sub process_courselog {
         if (! defined($host)) { $host = 'unknown'; }          if (! defined($host)) { $host = 'unknown'; }
         my $prevchunk = 'none';          my $prevchunk = 'none';
         foreach my $chunk (split(/\&\&\&/,$log)) {          foreach my $chunk (split(/\&\&\&/,$log)) {
               if (length($chunk) > 20000) {
                   # avoid putting too much data into the database
                   # (usually an uploaded file or something similar)
                   if (! &savechunk(\$chunk,$timestamp,$host)) {
                       close(IN);
                       return undef;
                   }
                   next;
               }
             my $warningflag = '';              my $warningflag = '';
     my ($time,$res,$uname,$udom,$action,@values)= split(/:/,$chunk);      my ($time,$res,$uname,$udom,$action,@values)= split(/:/,$chunk);
               #
             if (! defined($res) || $res =~ /^\s*$/) {              if (! defined($res) || $res =~ /^\s*$/) {
                 $res = '/adm/roles';                  $res = '/adm/roles';
                 $action = 'LOGIN';                  $action = 'LOGIN';
Line 486  sub process_courselog { Line 516  sub process_courselog {
             if ($action !~ /^(LOGIN|VIEW|POST|CSTORE|STORE)$/) {              if ($action !~ /^(LOGIN|VIEW|POST|CSTORE|STORE)$/) {
                 $warningflag .= 'action';                  $warningflag .= 'action';
                 print $error_fh 'full log entry:'.$log.$/;                  print $error_fh 'full log entry:'.$log.$/;
                 print $error_fh 'error on chunk:'.$chunk.$/;                  print $error_fh 'error on chunk (saving)'.$/;
                 $logthis->('(action) Unable to parse '.$/.$chunk.$/.                  if (! &savechunk(\$chunk,$timestamp,$host)) {
                       close(IN);
                       return undef;
                   }
                   $logthis->('(action) Unable to parse chunk'.$/.
                          'got '.                           'got '.
                          'time = '.$time.$/.                           'time = '.$time.$/.
                          'res  = '.$res.$/.                           'res  = '.$res.$/.
Line 524  sub process_courselog { Line 558  sub process_courselog {
     }      }
     close IN;      close IN;
     return $linecount;      return $linecount;
       ##
       ##
       sub savechunk {
           my ($chunkref,$timestamp,$host) = @_;
           my $chunk = &escape(${$chunkref});
           if (! open(CHUNKFILE,">>$chunk_filename") ||
               ! print CHUNKFILE $timestamp.':'.$host.':'.$chunk.$/) {
               # abort
               close(CHUNKFILE);
               return 0;
           }
           close(CHUNKFILE);
           return 1;
       }
 }  }
   
   
Line 700  sub read_id_tables { Line 748  sub read_id_tables {
   
 sub get_id {  sub get_id {
     my ($table,$fieldname,$value) = @_;      my ($table,$fieldname,$value) = @_;
     if (exists($IDs{$table}->{$value})) {      if (exists($IDs{$table}->{$value}) && $IDs{$table}->{$value} =~ /^\d+$/) {
         return $IDs{$table}->{$value};          return $IDs{$table}->{$value};
     } else {      } else {
         # insert into the table - if the item already exists, that is          # insert into the table - if the item already exists, that is
         # okay.          # okay.
         my $result = &Apache::lonmysql::store_row($table,[undef,$value]);          my $result = &Apache::lonmysql::store_row($table,[undef,$value]);
         if (! defined($result)) {          if (! defined($result)) {
             warn("Got error on id insert for $value\n".&Apache::lonmysql::get_error());              warn("Got error on id insert for $value\n".
                    &Apache::lonmysql::get_error());
         }          }
         # get the id          # get the id
         my @Data =           my $id = &Apache::lonmysql::get_dbh()->{'mysql_insertid'};
             &Apache::lonmysql::get_rows($table,qq{$fieldname='$value'});          if (defined($id)) {
         if (@Data) {              $IDs{$table}->{$value}=$id;
             $IDs{$table}->{$value}=$Data[0]->[0];  
             return $IDs{$table}->{$value};  
         } else {          } else {
             $logthis->("Unable to retrieve id for $table $fieldname $value");              $logthis->("Unable to retrieve id for $table $fieldname $value");
             return undef;              return undef;
Line 788  sub backup_tables_as_xml { Line 835  sub backup_tables_as_xml {
 ##  ##
 ###############################################################  ###############################################################
 ###############################################################  ###############################################################
   {
       my @fields = ('resource','time',
                     'student','action','idx','machine','action_values');
       my %ids = ();
 sub load_backup_xml_tables {  sub load_backup_xml_tables {
     my ($filename,$tables) = @_;      my ($filename,$tables) = @_;
       my $dbh = &Apache::lonmysql::get_dbh();
     my $xmlfh;      my $xmlfh;
     open($xmlfh,"cat $filename | gzip -d - |");      open($xmlfh,"cat $filename | gzip -d - |");
     if (! defined($xmlfh)) {      if (! defined($xmlfh)) {
         return ('error:unable to read '.$filename);          return ('error:unable to read '.$filename);
     }      }
     my $dbh = &Apache::lonmysql::get_dbh();      #
     my $parser = HTML::TokeParser->new($xmlfh);      %ids = (resource=> {"\0count"=>1},
     $parser->xml_mode('1');              student=> {"\0count"=>1},
     &store_entry();              machine=> {"\0count"=>1});
       #
     my %data;      my %data;
     while (my $token = $parser->get_token()) {      while (my $inputline = <$xmlfh>) {
         if ($token->[0] eq 'S' && $token->[1] eq 'row') {          my ($resource,$time,undef,$student,$action,$machine,$action_values) = 
             undef(%data);              ($inputline =~ m{<row>
         }                                   <resource>(.*)</resource>
         foreach my $tag ('resource','time','idx',                                   <time>(.*)</time>
                          'student','action','machine','action_values') {                                   <idx>(.*)</idx>
             if ($token->[0] eq 'S' && $token->[1] eq $tag) {                                   <student>(.*)</student>
                 my $text = $parser->get_text("/$tag");                                   <action>(.*)</action>
                 $data{$tag} = $text;                                   <machine>(.*)</machine>
             }                                   <action_values>(.*)</action_values>
         }                                   </row>$
         if ($token->[0] eq 'E' && $token->[1] eq 'row') {                               }x
             $data{'action_values'} =qq{'$data{'action_values'}'};               );
             my $error = &store_entry($dbh,$tables,\%data);          my $resource_id = &xml_get_id('resource',$resource);
           my $student_id  = &xml_get_id('student',$student);
           my $machine_id  = &xml_get_id('machine',$machine);
           &xml_store_activity_row(map { defined($_)?$dbh->quote($_):'' 
                                     } ($resource_id,
                                        $time,
                                        $student_id,
                                        $action,
                                        'NULL',
                                        $machine_id,
                                        $action_values));
       }
       &xml_store_activity_row();
       close($xmlfh);
       # Store id tables
       while (my ($id_name,$id_data) = each(%ids)) {
           if ($id_name eq 'resource') { $id_name = 'res'; }
           delete($id_data->{"\0count"});
           &xml_store_id_table($id_name,$id_data);
       }
       return;
   }
   
   sub xml_get_id {
       my ($table,$element) = @_;
       if (! exists($ids{$table}->{$element})) {
           $ids{$table}->{$element} = $ids{$table}->{"\0count"}++;
       }
       return $ids{$table}->{$element};
   }
   
   {
       my @data_rows;
   sub xml_store_activity_row {
       my @data = @_;
       if (scalar(@data)) {
           push(@data_rows,[@data]);
       }
       if (! scalar(@data) || scalar(@data_rows) > 500) {
           if (! &Apache::lonmysql::bulk_store_rows($tables{'activity'},
                                                    scalar(@{$data_rows[0]}),
                                                    \@data_rows)) {
               $logthis->("Error:".&Apache::lonmysql::get_error());
               warn("Error:".&Apache::lonmysql::get_error());
           } else {
               undef(@data_rows);
         }          }
     }      }
     &store_entry($dbh,$tables);  
     return;      return;
 }  }
   
   }
   
   sub xml_store_id_table {
       my ($table,$tabledata) =@_;
       my $dbh = &Apache::lonmysql::get_dbh();
       if (! &Apache::lonmysql::bulk_store_rows
           ($tables{$table},2,
            [map{[$tabledata->{$_},$dbh->quote($_)]} keys(%$tabledata)])) {
           $logthis->("Error:".&Apache::lonmysql::get_error());
           warn "Error:".&Apache::lonmysql::get_error().$/;
       }
   }
   
   } # End of load xml scoping
   
 #######################################################################  #######################################################################
 #######################################################################  #######################################################################
 ##  ##
 ## store_entry - accumulate data to be inserted into the database  ## store_entry - accumulate data to be inserted into the database
 ##   ##
 ## Pass no values in to clear accumulator  ## Pass no values in to clear accumulator
 ## Pass ($dbh,\%tables) to initiate storage of values  ## Pass ($dbh,\%tables) to initiate storage of values
 ## Pass ($dbh,\%tables,\%data) to use normally  ## Pass ($dbh,\%tables,\%data) to use normally
 ##  ##
 #######################################################################  #######################################################################
 #######################################################################  #######################################################################
   
 {  {
     my @rows;      my @rows;
     my $max_row_count = 100;  
   
 sub store_entry {  sub store_entry {
       my $max_row_count = 100;
     if (! @_) {      if (! @_) {
         undef(@rows);          undef(@rows);
         return '';          return '';
Line 870  sub store_entry { Line 980  sub store_entry {
                     $machine_id,                      $machine_id,
                     $data->{'action_values'}]);                      $data->{'action_values'}]);
     }      }
     if (defined($tables) &&       if (defined($tables) &&
         ( (! defined($data) && scalar(@rows)) || scalar(@rows)>$max_row_count)          ( (! defined($data) && scalar(@rows)) || scalar(@rows)>$max_row_count)
         ){          ){
         # Store the rows          # Store the rows
         my $result =           my $result =
             &Apache::lonmysql::bulk_store_rows($tables->{'activity'},              &Apache::lonmysql::bulk_store_rows($tables->{'activity'},
                                                undef,                                                 undef,
                                                \@rows);                                                 \@rows);
Line 886  sub store_entry { Line 996  sub store_entry {
         undef(@rows);          undef(@rows);
         return $result if (! defined($data));          return $result if (! defined($data));
     }      }
   
     return '';      return '';
 }  }
   

Removed from v.1.14  
changed lines
  Added in v.1.23


FreeBSD-CVSweb <freebsd-cvsweb@FreeBSD.org>