version 1.9, 2004/12/22 14:58:15
|
version 1.25, 2014/11/24 02:36:34
|
Line 48
|
Line 48
|
# parameter is not set $logthis is set to ¬hing, which does what you |
# parameter is not set $logthis is set to ¬hing, which does what you |
# would expect. |
# would expect. |
# |
# |
|
|
use strict; |
use strict; |
use DBI; |
use DBI; |
use lib '/home/httpd/lib/perl/Apache'; |
|
use lib '/home/httpd/lib/perl/'; |
use lib '/home/httpd/lib/perl/'; |
use LONCAPA::Configuration(); |
use LONCAPA::Configuration(); |
use Apache::lonmysql(); |
use Apache::lonmysql(); |
use lonmysql(); |
|
use Time::HiRes(); |
use Time::HiRes(); |
use Getopt::Long(); |
use Getopt::Long(); |
use IO::File; |
use IO::File; |
use File::Copy; |
use File::Copy; |
use Fcntl qw(:flock); |
use Fcntl qw(:flock); |
|
use HTML::TokeParser; |
|
|
# |
# |
# Determine parameters |
# Determine parameters |
my ($help,$course,$domain,$drop,$file,$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" => \$file, |
"logfile=s" => \$logfile, |
|
"srcfile=s" => \$srcfile, |
|
"justloadxml=s" => \$xmlfile, |
"timerun" => \$time_run, |
"timerun" => \$time_run, |
"nocleanup" => \$nocleanup, |
"nocleanup" => \$nocleanup, |
"drop" => \$drop, |
"dropwhendone" => \$drop_when_done, |
"log" => \$log); |
"log" => \$log); |
if (! defined($course) || $help) { |
if (! defined($course) || $help) { |
print<<USAGE; |
print<<USAGE; |
Line 81 parse_activity_log.pl
|
Line 81 parse_activity_log.pl
|
Process a lon-capa activity log into a database. |
Process a lon-capa activity log into a database. |
Parameters: |
Parameters: |
course Required |
course Required |
domain Optional |
domain optional |
backup optional if present, backup the activity log file |
backup optional if present, backup the activity log file |
before processing it |
before processing it |
drop optional if present, drop all course |
dropwhendone optional if present, drop all course |
specific activity log tables. |
specific activity log tables after processing. |
file optional Specify the file to parse, including path |
srcfile optional Specify the file to parse, including path |
time optional if present, print out timing data |
time optional if present, print out timing data |
nocleanup optional if present, do not remove old files |
nocleanup optional if present, do not remove old files |
log optional if present, prepare log file of activity |
log optional if present, prepare log file of activity |
|
logfile optional specifies the logfile to use |
Examples: |
Examples: |
$0 -course=123456abcdef -domain=msu |
$0 -course=123456abcdef -domain=msu |
$0 -course=123456abcdef -file=activity.log |
$0 -course=123456abcdef -srcfile=activity.log |
|
$0 -course-123456abcdef -log -logfile=/tmp/logfile -dropwhendone |
USAGE |
USAGE |
exit; |
exit; |
} |
} |
Line 118 if (! defined($domain) || $domain eq '')
|
Line 120 if (! defined($domain) || $domain eq '')
|
## |
## |
## Set up logging code |
## Set up logging code |
my $logthis = \¬hing; |
my $logthis = \¬hing; |
|
|
if ($log) { |
if ($log) { |
my $logfile = $perlvar{'lonDaemons'}.'/tmp/parse_activity_log.log.'.time; |
if (! $logfile) { |
|
$logfile = $perlvar{'lonDaemons'}.'/tmp/parse_activity_log.log.'.time; |
|
} |
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 135 if ($log) {
|
Line 140 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 $gz_sql_filename; # the gzipped mysql backup data file name. |
|
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 |
if ($file) { |
my $chunk_filename; # where we save data we are not going to write to db |
$sourcefilename = $file; |
if ($srcfile) { |
|
$sourcefilename = $srcfile; |
} else { |
} else { |
$sourcefilename = &get_filename($course,$domain); |
$sourcefilename = &get_filename($course,$domain); |
} |
} |
my $sql_filename = $sourcefilename; |
my $sql_filename = $sourcefilename; |
$sql_filename =~ s|[^/]*$|activity.log.sql|; |
$sql_filename =~ s|[^/]*$|activity.log.sql|; |
$gz_sql_filename = $sql_filename.'.gz'; |
my $gz_sql_filename = $sql_filename.'.gz'; |
|
# |
|
$chunk_filename = $sourcefilename.".unprocessed_chunks"; |
|
# |
|
my $xml_filename = $sourcefilename; |
|
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|; |
$logthis->('Beginning logging '.time); |
$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 |
## |
## |
my $prefix = $course.'_'.$domain.'_'; |
my %tables = &table_names($course,$domain); |
my $student_table = $prefix.'students'; |
|
my $student_table_def = |
my $student_table_def = |
{ id => $student_table, |
{ id => $tables{'student'}, |
permanent => 'no', |
permanent => 'no', |
columns => [ |
columns => [ |
{ name => 'student_id', |
{ name => 'student_id', |
Line 203 my $student_table_def =
|
Line 214 my $student_table_def =
|
'PRIMARY KEY' => ['student_id',], |
'PRIMARY KEY' => ['student_id',], |
}; |
}; |
|
|
my $res_table = $prefix.'resource'; |
|
my $res_table_def = |
my $res_table_def = |
{ id => $res_table, |
{ id => $tables{'res'}, |
permanent => 'no', |
permanent => 'no', |
columns => [{ name => 'res_id', |
columns => [{ name => 'res_id', |
type => 'MEDIUMINT UNSIGNED', |
type => 'MEDIUMINT UNSIGNED', |
Line 218 my $res_table_def =
|
Line 228 my $res_table_def =
|
'PRIMARY KEY' => ['res_id'], |
'PRIMARY KEY' => ['res_id'], |
}; |
}; |
|
|
#my $action_table = $prefix.'actions'; |
|
#my $action_table_def = |
#my $action_table_def = |
#{ id => $action_table, |
#{ id => $action_table, |
# permanent => 'no', |
# permanent => 'no', |
Line 233 my $res_table_def =
|
Line 242 my $res_table_def =
|
# 'PRIMARY KEY' => ['action_id',], |
# 'PRIMARY KEY' => ['action_id',], |
#}; |
#}; |
|
|
my $machine_table = $prefix.'machine_table'; |
|
my $machine_table_def = |
my $machine_table_def = |
{ id => $machine_table, |
{ id => $tables{'machine'}, |
permanent => 'no', |
permanent => 'no', |
columns => [{ name => 'machine_id', |
columns => [{ name => 'machine_id', |
type => 'MEDIUMINT UNSIGNED', |
type => 'MEDIUMINT UNSIGNED', |
Line 248 my $machine_table_def =
|
Line 256 my $machine_table_def =
|
'PRIMARY KEY' => ['machine_id',], |
'PRIMARY KEY' => ['machine_id',], |
}; |
}; |
|
|
my $activity_table = $prefix.'activity'; |
|
my $activity_table_def = |
my $activity_table_def = |
{ id => $activity_table, |
{ id => $tables{'activity'}, |
permanent => 'no', |
permanent => 'no', |
columns => [ |
columns => [ |
{ name => 'res_id', |
{ name => 'res_id', |
Line 282 my $activity_table_def =
|
Line 289 my $activity_table_def =
|
|
|
my @Activity_Table = ($activity_table_def); |
my @Activity_Table = ($activity_table_def); |
my @ID_Tables = ($student_table_def,$res_table_def,$machine_table_def); |
my @ID_Tables = ($student_table_def,$res_table_def,$machine_table_def); |
|
|
## |
## |
## End of table definitions |
## End of table definitions |
## |
## |
|
$logthis->('tables = '.join(',',keys(%tables))); |
|
|
$logthis->('Connectiong to mysql'); |
$logthis->('Connectiong to mysql'); |
&Apache::lonmysql::set_mysql_user_and_password('www', |
&Apache::lonmysql::set_mysql_user_and_password('www', |
Line 292 $logthis->('Connectiong to mysql');
|
Line 301 $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'); |
|
|
if ($drop) { &drop_tables(); $logthis->('dropped tables'); } |
&update_process_name($course.'@'.$domain." loading existing data"); |
|
my $missing_table = &check_for_missing_tables(values(%tables)); |
if (-s $gz_sql_filename) { |
if (-s $gz_sql_filename && ! -s $gz_xml_filename) { |
my $backup_modification_time = (stat($gz_sql_filename))[9]; |
my $backup_modification_time = (stat($gz_sql_filename))[9]; |
$logthis->($gz_sql_filename.' was last modified '. |
$logthis->($gz_sql_filename.' was last modified '. |
localtime($backup_modification_time). |
localtime($backup_modification_time). |
'('.$backup_modification_time.')'); |
'('.$backup_modification_time.')'); |
# Check for missing tables |
if ($missing_table) { |
my @Current_Tables = &Apache::lonmysql::tables_in_db(); |
# If the backup happened prior to the last table modification, |
$logthis->(join(',',@Current_Tables)); |
# we need to save the tables. |
my %Found; |
if (&latest_table_modification_time() > $backup_modification_time) { |
foreach my $tablename (@Current_Tables) { |
# Save the current tables in case we need them another time. |
foreach my $table (@Activity_Table,@ID_Tables) { |
$logthis->('Backing existing tables up'); |
if ($tablename eq $table->{'id'}) { |
&backup_tables_as_xml($gz_xml_filename.'.save_'.time,\%tables); |
$Found{$tablename}++; |
|
} |
|
} |
|
} |
|
$logthis->('Found tables '.join(',',keys(%Found))); |
|
my $missing_a_table = 0; |
|
foreach my $table (@Activity_Table,@ID_Tables) { |
|
# Hmmm, should I dump the tables? |
|
if (! $Found{$table->{'id'}}) { |
|
$logthis->('Missing table '.$table->{'id'}); |
|
$missing_a_table = 1; |
|
last; |
|
} |
} |
|
$time_this->(); |
|
&load_backup_sql_tables($gz_sql_filename); |
|
&backup_tables_as_xml($gz_xml_filename,\%tables); |
|
$time_this->('load backup tables'); |
} |
} |
if ($missing_a_table) { |
} elsif (-s $gz_xml_filename) { |
|
my $backup_modification_time = (stat($gz_xml_filename))[9]; |
|
$logthis->($gz_xml_filename.' was last modified '. |
|
localtime($backup_modification_time). |
|
'('.$backup_modification_time.')'); |
|
if ($missing_table) { |
my $table_modification_time = $backup_modification_time; |
my $table_modification_time = $backup_modification_time; |
# If the backup happened prior to the last table modification, |
# If the backup happened prior to the last table modification, |
foreach my $table (@Activity_Table,@ID_Tables) { |
# we need to save the tables. |
my %tabledata = &Apache::lonmysql::table_information($table->{'id'}); |
if (&latest_table_modification_time() > $backup_modification_time) { |
next if (! scalar(keys(%tabledata))); # table does not exist |
|
if ($table_modification_time < $tabledata{'Update_time'}) { |
|
$table_modification_time = $tabledata{'Update_time'}; |
|
} |
|
} |
|
$logthis->("Table modification time = ".$table_modification_time); |
|
if ($table_modification_time > $backup_modification_time) { |
|
# Save the current tables in case we need them another time. |
# Save the current tables in case we need them another time. |
my $backup_name = $gz_sql_filename.'.'.time; |
$logthis->('Backing existing tables up'); |
$logthis->('Backing existing tables up in '.$backup_name); |
&backup_tables_as_xml($gz_xml_filename.'.save_'.time,\%tables); |
&backup_tables($backup_name); |
|
} |
} |
$time_this->(); |
$time_this->(); |
&load_backup_tables($gz_sql_filename); |
# We have to make our own tables for the xml format |
|
&drop_tables(); |
|
&create_tables(); |
|
&load_backup_xml_tables($gz_xml_filename,\%tables); |
$time_this->('load backup tables'); |
$time_this->('load backup tables'); |
} |
} |
|
} |
|
|
|
if (defined($xmlfile)) { |
|
&clean_up_and_exit(0); |
} |
} |
|
|
## |
## |
Line 354 $logthis->('creating tables');
|
Line 359 $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 370 my $error_fh = IO::File->new(">>$error_f
|
Line 375 my $error_fh = IO::File->new(">>$error_f
|
## |
## |
## Parse the course log |
## Parse the course log |
$logthis->('processing course log'); |
$logthis->('processing course log'); |
|
&update_process_name($course.'@'.$domain." processing new data"); |
if (-s $newfilename) { |
if (-s $newfilename) { |
my $result = &process_courselog($newfilename,$error_fh); |
my $result = &process_courselog($newfilename,$error_fh,\%tables); |
|
&update_process_name($course.'@'.$domain." backing up new data"); |
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.'.'.$/. |
&backup_tables($gz_sql_filename); |
'Backing up tables'); |
|
&backup_tables_as_xml($gz_xml_filename,\%tables); |
$time_this->('write backup tables'); |
$time_this->('write backup tables'); |
} |
} |
|
if ($drop_when_done) { &drop_tables(); $logthis->('dropped tables'); } |
} |
} |
close($error_fh); |
close($error_fh); |
|
|
Line 401 if ($time_run) {
|
Line 410 if ($time_run) {
|
$logthis->(&outputtimes()); |
$logthis->(&outputtimes()); |
} |
} |
|
|
if ($log) { |
&clean_up_and_exit(0); |
close LOGFILE; |
|
|
######################################################## |
|
######################################################## |
|
|
|
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 $exit_code; |
} |
} |
|
|
exit 0; # Everything is okay, so end here before it gets worse. |
######################################################## |
|
######################################################## |
|
sub table_names { |
|
my ($course,$domain) = @_; |
|
my $prefix = $course.'_'.$domain.'_'; |
|
# |
|
my %tables = |
|
( student =>&Apache::lonmysql::fix_table_name($prefix.'students'), |
|
res =>&Apache::lonmysql::fix_table_name($prefix.'resource'), |
|
machine =>&Apache::lonmysql::fix_table_name($prefix.'machine_table'), |
|
activity=>&Apache::lonmysql::fix_table_name($prefix.'activity'), |
|
); |
|
return %tables; |
|
} |
|
|
######################################################## |
######################################################## |
######################################################## |
######################################################## |
Line 417 exit 0; # Everything is okay, so end h
|
Line 455 exit 0; # Everything is okay, so end h
|
# |
# |
# Returns the number of lines in the activity.log file that were processed. |
# Returns the number of lines in the activity.log file that were processed. |
sub process_courselog { |
sub process_courselog { |
my ($inputfile,$error_fh) = @_; |
my ($inputfile,$error_fh,$tables) = @_; |
if (! open(IN,$inputfile)) { |
if (! open(IN,$inputfile)) { |
warn "Unable to open '$inputfile' for reading"; |
warn "Unable to open '$inputfile' for reading"; |
$logthis->("Unable to open '$inputfile' for reading"); |
$logthis->("Unable to open '$inputfile' for reading"); |
Line 426 sub process_courselog {
|
Line 464 sub process_courselog {
|
my ($linecount,$insertcount); |
my ($linecount,$insertcount); |
my $dbh = &Apache::lonmysql::get_dbh(); |
my $dbh = &Apache::lonmysql::get_dbh(); |
# |
# |
# Timing variables |
&store_entry(); |
my @RowData; |
|
while (my $line=<IN>){ |
while (my $line=<IN>){ |
# last if ($linecount > 1000); |
# last if ($linecount > 1000); |
# |
# |
Line 437 sub process_courselog {
|
Line 474 sub process_courselog {
|
$linecount++; |
$linecount++; |
# print $linecount++.$/; |
# print $linecount++.$/; |
my ($timestamp,$host,$log)=split(/\:/,$line,3); |
my ($timestamp,$host,$log)=split(/\:/,$line,3); |
$time_this->('splitline'); |
|
# |
# |
# $log has the actual log entries; currently still escaped, and |
# $log has the actual log entries; currently still escaped, and |
# %26(timestamp)%3a(url)%3a(user)%3a(domain) |
# %26(timestamp)%3a(url)%3a(user)%3a(domain) |
Line 445 sub process_courselog {
|
Line 481 sub process_courselog {
|
# %3aPOST%3a(name)%3d(value)%3a(name)%3d(value) |
# %3aPOST%3a(name)%3d(value)%3a(name)%3d(value) |
# or |
# or |
# %3aCSTORE%3a(name)%3d(value)%26(name)%3d(value) |
# %3aCSTORE%3a(name)%3d(value)%26(name)%3d(value) |
|
# or |
|
# %3aPUTSTORE%3a(name)%3d(value)%26(name)%3d(value) |
# |
# |
# get delimiter between timestamped entries to be &&& |
# get delimiter between timestamped entries to be &&& |
$log=~s/\%26(\d{9,10})\%3a/\&\&\&$1\%3a/g; |
$log=~s/\%26(\d{9,10})\%3a/\&\&\&$1\%3a/g; |
$log = &unescape($log); |
$log = &unescape($log); |
$time_this->('translate_and_unescape'); |
|
# now go over all log entries |
# now go over all log entries |
if (! defined($host)) { $host = 'unknown'; } |
if (! defined($host)) { $host = 'unknown'; } |
my $machine_id = &get_id($machine_table,'machine',$host); |
|
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 = ''; |
$time_this->(); |
|
my ($time,$res,$uname,$udom,$action,@values)= split(/:/,$chunk); |
my ($time,$res,$uname,$udom,$action,@values)= split(/:/,$chunk); |
my $student = $uname.':'.$udom; |
# |
if (! defined($res) || $res =~ /^\s*$/) { |
if (! defined($res) || $res =~ /^\s*$/) { |
$res = '/adm/roles'; |
$res = '/adm/roles'; |
$action = 'LOGIN'; |
$action = 'LOGIN'; |
Line 469 sub process_courselog {
|
Line 513 sub process_courselog {
|
if (! defined($action) || $action eq '') { |
if (! defined($action) || $action eq '') { |
$action = 'VIEW'; |
$action = 'VIEW'; |
} |
} |
if ($action !~ /^(LOGIN|VIEW|POST|CSTORE|STORE)$/) { |
if ($action !~ /^(LOGIN|VIEW|POST|CSTORE|STORE|PUTSTORE)$/) { |
$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.$/. |
'uname= '.$uname.$/. |
'uname= '.$uname.$/. |
'udom = '.$udom.$/. |
'udom = '.$udom.$/. |
'action='.$action.$/. |
'action='.$action.$/. |
'@values = '.join(':',@values)); |
'@values = '.join('&',@values)); |
next; #skip it if we cannot understand what is happening. |
next; #skip it if we cannot understand what is happening. |
} |
} |
if (! defined($student) || $student eq ':') { |
|
$student = 'unknown'; |
|
$warningflag .= 'student'; |
|
} |
|
if (! defined($res) || $res =~ /^\s*$/) { |
|
$res = 'unknown'; |
|
$warningflag .= 'res'; |
|
} |
|
if (! defined($action) || $action =~ /^\s*$/) { |
|
$action = 'unknown'; |
|
$warningflag .= 'action'; |
|
} |
|
if (! defined($time) || $time !~ /^\d+$/) { |
|
$time = 0; |
|
$warningflag .= 'time'; |
|
} |
|
# |
|
$time_this->('split_and_error_check'); |
|
my $student_id = &get_id($student_table,'student',$student); |
|
my $res_id = &get_id($res_table,'resource',$res); |
|
# my $action_id = &get_id($action_table,'action',$action); |
|
my $sql_time = &Apache::lonmysql::sqltime($time); |
|
# |
# |
if (! defined($student_id) || $student_id eq '') { |
my %data = (student => $uname.':'.$udom, |
$warningflag.='student_id'; |
resource => $res, |
} |
machine => $host, |
if (! defined($res_id) || $res_id eq '') { |
action => $action, |
$warningflag.='res_id'; |
time => &Apache::lonmysql::sqltime($time)); |
} |
if ($action eq 'POST') { |
# if (! defined($action_id) || $action_id eq '') { |
$data{'action_values'} = |
# $warningflag.='action_id'; |
$dbh->quote(join('&',map { &escape($_); } @values)); |
# } |
} else { |
if ($warningflag ne '') { |
$data{'action_values'} = $dbh->quote(join('&',@values)); |
print $error_fh 'full log entry:'.$log.$/; |
} |
print $error_fh 'error on chunk:'.$chunk.$/; |
my $error = &store_entry($dbh,$tables,\%data); |
$logthis->('warningflag ('.$warningflag.') on chunk '. |
if ($error) { |
$/.$chunk.$/.'prevchunk = '.$/.$prevchunk); |
$logthis->('error store_entry:'.$error." on %data"); |
$prevchunk .= $chunk; |
|
next; # skip this chunk |
|
} |
} |
# |
|
my $values = $dbh->quote(join('',@values)); |
|
$time_this->('get_ids'); |
|
# |
|
my $row = [$res_id, |
|
qq{'$sql_time'}, |
|
$student_id, |
|
"'".$action."'", |
|
# $action_id, |
|
qq{''}, # idx |
|
$machine_id, |
|
$values]; |
|
push(@RowData,$row); |
|
$time_this->('push_row'); |
|
$prevchunk = $chunk; |
$prevchunk = $chunk; |
# |
|
} |
|
$time_this->(); |
|
if ((scalar(@RowData) > 0) && ($linecount % 100 == 0)) { |
|
my $result = &Apache::lonmysql::bulk_store_rows($activity_table, |
|
undef, |
|
\@RowData); |
|
# $logthis->('result = '.$result); |
|
$time_this->('bulk_store_rows'); |
|
if (! defined($result)) { |
|
my $error = &Apache::lonmysql::get_error(); |
|
warn "Error occured during insert.".$error; |
|
$logthis->('error = '.$error); |
|
} |
|
undef(@RowData); |
|
} |
} |
} |
} |
if (@RowData) { |
my $result = &store_entry($dbh,$tables); |
$time_this->(); |
if (! defined($result)) { |
$logthis->('storing '.$linecount); |
my $error = &Apache::lonmysql::get_error(); |
my $result = &Apache::lonmysql::bulk_store_rows($activity_table, |
warn "Error occured during insert.".$error; |
undef, |
$logthis->('error = '.$error); |
\@RowData); |
|
$logthis->('result = '.$result); |
|
$time_this->('bulk_store_rows'); |
|
if (! defined($result)) { |
|
my $error = &Apache::lonmysql::get_error(); |
|
warn "Error occured during insert.".$error; |
|
$logthis->('error = '.$error); |
|
} |
|
undef(@RowData); |
|
} |
} |
close IN; |
close IN; |
# print "Number of lines: ".$linecount.$/; |
|
# print "Number of inserts: ".$insertcount.$/; |
|
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; |
|
} |
} |
} |
|
|
|
|
## |
## |
## Somtimes, instead of doing something, doing nothing is appropriate. |
## default value for $logthis and $time_this |
sub nothing { |
sub nothing { |
return; |
return; |
} |
} |
|
|
## |
## |
## Logging routine |
## Logging routine (look for $log) |
## |
## |
sub log_to_file { |
sub log_to_file { |
my ($input)=@_; |
my ($input)=@_; |
Line 625 sub outputtimes {
|
Line 623 sub outputtimes {
|
|
|
} |
} |
|
|
|
sub latest_table_modification_time { |
|
my $latest_time; |
|
foreach my $table (@Activity_Table,@ID_Tables) { |
|
my %tabledata = &Apache::lonmysql::table_information($table->{'id'}); |
|
next if (! scalar(keys(%tabledata))); # table does not exist |
|
if (! defined($latest_time) || |
|
$latest_time < $tabledata{'Update_time'}) { |
|
$latest_time = $tabledata{'Update_time'}; |
|
} |
|
} |
|
return $latest_time; |
|
} |
|
|
|
sub check_for_missing_tables { |
|
my @wanted_tables = @_; |
|
# Check for missing tables |
|
my @Current_Tables = &Apache::lonmysql::tables_in_db(); |
|
my %Found; |
|
foreach my $tablename (@Current_Tables) { |
|
foreach my $table (@wanted_tables) { |
|
if ($tablename eq $table) { |
|
$Found{$tablename}++; |
|
} |
|
} |
|
} |
|
$logthis->('Found tables '.join(',',keys(%Found))); |
|
my $missing_a_table = 0; |
|
foreach my $table (@wanted_tables) { |
|
if (! $Found{$table}) { |
|
$logthis->('Missing table '.$table); |
|
$missing_a_table = 1; |
|
last; |
|
} |
|
} |
|
return $missing_a_table; |
|
} |
|
|
## |
## |
## Use mysqldump to store backups of the tables |
## Use mysqldump to store backups of the tables |
## |
## |
sub backup_tables { |
sub backup_tables_as_sql { |
my ($gz_sql_filename) = @_; |
my ($gz_sql_filename) = @_; |
my $command = qq{mysqldump --opt loncapa }; |
my $command = qq{mysqldump --quote-names --opt loncapa }; |
|
|
foreach my $table (@ID_Tables,@Activity_Table) { |
foreach my $table (@ID_Tables,@Activity_Table) { |
my $tablename = $table->{'id'}; |
my $tablename = $table->{'id'}; |
|
$tablename =~ s/\`//g; |
$command .= $tablename.' '; |
$command .= $tablename.' '; |
} |
} |
$command .= '| gzip >'.$gz_sql_filename; |
$command .= '| gzip >'.$gz_sql_filename; |
Line 645 sub backup_tables {
|
Line 679 sub backup_tables {
|
## |
## |
## Load in mysqldumped files |
## Load in mysqldumped files |
## |
## |
sub load_backup_tables { |
sub load_backup_sql_tables { |
my ($gz_sql_filename) = @_; |
my ($gz_sql_filename) = @_; |
if (-s $gz_sql_filename) { |
if (-s $gz_sql_filename) { |
$logthis->('loading data from gzipped sql file'); |
$logthis->('loading data from gzipped sql file'); |
Line 674 sub get_filename {
|
Line 708 sub get_filename {
|
sub create_tables { |
sub create_tables { |
foreach my $table (@ID_Tables,@Activity_Table) { |
foreach my $table (@ID_Tables,@Activity_Table) { |
my $table_id = &Apache::lonmysql::create_table($table); |
my $table_id = &Apache::lonmysql::create_table($table); |
# print STDERR "Unable to create table ".$table->{'id'}.$/; |
|
# print STDERR join($/,&Apache::lonmysql::build_table_creation_request($table)).$/; |
|
if (! defined($table_id)) { |
if (! defined($table_id)) { |
warn "Unable to create table ".$table->{'id'}.$/; |
warn "Unable to create table ".$table->{'id'}.$/; |
warn join($/,&Apache::lonmysql::build_table_creation_request($table)).$/; |
$logthis->('Unable to create table '.$table->{'id'}); |
|
$logthis->(join($/,&Apache::lonmysql::build_table_creation_request($table))); |
return 0; |
return 0; |
} |
} |
} |
} |
Line 715 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 739 sub get_id {
|
Line 771 sub get_id {
|
|
|
} # End of ID scoping |
} # End of ID scoping |
|
|
|
############################################################### |
|
############################################################### |
|
## |
|
## Save as XML |
|
## |
|
############################################################### |
|
############################################################### |
|
sub backup_tables_as_xml { |
|
my ($filename,$tables) = @_; |
|
open(XMLFILE,"|gzip - > $filename") || return ('error:unable to write '.$filename); |
|
my $query = qq{ |
|
SELECT B.resource, |
|
A.time, |
|
A.idx, |
|
C.student, |
|
A.action, |
|
E.machine, |
|
A.action_values |
|
FROM $tables->{'activity'} AS A |
|
LEFT JOIN $tables->{'res'} AS B ON B.res_id=A.res_id |
|
LEFT JOIN $tables->{'student'} AS C ON C.student_id=A.student_id |
|
LEFT JOIN $tables->{'machine'} AS E ON E.machine_id=A.machine_id |
|
ORDER BY A.time DESC |
|
}; |
|
$query =~ s/\s+/ /g; |
|
my $dbh = &Apache::lonmysql::get_dbh(); |
|
my $sth = $dbh->prepare($query); |
|
if (! $sth->execute()) { |
|
$logthis->('<font color="blue">'. |
|
'WARNING: Could not retrieve from database:'. |
|
$sth->errstr().'</font>'); |
|
return undef; |
|
} else { |
|
my ($res,$sqltime,$idx,$student,$action,$machine,$action_values); |
|
if ($sth->bind_columns(\$res,\$sqltime,\$idx,\$student,\$action, |
|
\$machine,\$action_values)) { |
|
|
|
while ($sth->fetch) { |
|
print XMLFILE '<row>'. |
|
qq{<resource>$res</resource>}. |
|
qq{<time>$sqltime</time>}. |
|
qq{<idx>$idx</idx>}. |
|
qq{<student>$student</student>}. |
|
qq{<action>$action</action>}. |
|
qq{<machine>$machine</machine>}. |
|
qq{<action_values>$action_values</action_values>}. |
|
'</row>'.$/; |
|
} |
|
} else { |
|
warn "Unable to bind to columns.\n"; |
|
return undef; |
|
} |
|
} |
|
close XMLFILE; |
|
return; |
|
} |
|
|
|
############################################################### |
|
############################################################### |
|
## |
|
## load as xml |
|
## |
|
############################################################### |
|
############################################################### |
|
{ |
|
my @fields = ('resource','time', |
|
'student','action','idx','machine','action_values'); |
|
my %ids = (); |
|
sub load_backup_xml_tables { |
|
my ($filename,$tables) = @_; |
|
my $dbh = &Apache::lonmysql::get_dbh(); |
|
my $xmlfh; |
|
open($xmlfh,"cat $filename | gzip -d - |"); |
|
if (! defined($xmlfh)) { |
|
return ('error:unable to read '.$filename); |
|
} |
|
# |
|
%ids = (resource=> {"\0count"=>1}, |
|
student=> {"\0count"=>1}, |
|
machine=> {"\0count"=>1}); |
|
# |
|
my %data; |
|
while (my $inputline = <$xmlfh>) { |
|
my ($resource,$time,undef,$student,$action,$machine,$action_values) = |
|
($inputline =~ m{<row> |
|
<resource>(.*)</resource> |
|
<time>(.*)</time> |
|
<idx>(.*)</idx> |
|
<student>(.*)</student> |
|
<action>(.*)</action> |
|
<machine>(.*)</machine> |
|
<action_values>(.*)</action_values> |
|
</row>$ |
|
}x |
|
); |
|
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); |
|
} |
|
} |
|
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 |
|
## |
|
## Pass no values in to clear accumulator |
|
## Pass ($dbh,\%tables) to initiate storage of values |
|
## Pass ($dbh,\%tables,\%data) to use normally |
|
## |
|
####################################################################### |
|
####################################################################### |
|
{ |
|
my @rows; |
|
|
|
sub store_entry { |
|
my $max_row_count = 100; |
|
if (! @_) { |
|
undef(@rows); |
|
return ''; |
|
} |
|
my ($dbh,$tables,$data) = @_; |
|
return if (! defined($tables)); |
|
if (defined($data)) { |
|
my $error; |
|
foreach my $field ('student','resource','action','time') { |
|
if (! defined($data->{$field}) || $data->{$field} eq ':' || |
|
$data->{$field}=~ /^\s*$/) { |
|
$error.=$field.','; |
|
} |
|
} |
|
if ($error) { $error=~s/,$//; return $error; } |
|
# |
|
my $student_id = &get_id($tables->{'student'},'student', |
|
$data->{'student'}); |
|
my $res_id = &get_id($tables->{'res'}, |
|
'resource',$data->{'resource'}); |
|
my $machine_id = &get_id($tables->{'machine'}, |
|
'machine',$data->{'machine'}); |
|
my $idx = $data->{'idx'}; if (! $idx) { $idx = "''"; } |
|
# |
|
push(@rows,[$res_id, |
|
qq{'$data->{'time'}'}, |
|
$student_id, |
|
qq{'$data->{'action'}'}, |
|
$idx, |
|
$machine_id, |
|
$data->{'action_values'}]); |
|
} |
|
if (defined($tables) && |
|
( (! defined($data) && scalar(@rows)) || scalar(@rows)>$max_row_count) |
|
){ |
|
# Store the rows |
|
my $result = |
|
&Apache::lonmysql::bulk_store_rows($tables->{'activity'}, |
|
undef, |
|
\@rows); |
|
if (! defined($result)) { |
|
my $error = &Apache::lonmysql::get_error(); |
|
warn "Error occured during insert.".$error; |
|
return $error; |
|
} |
|
undef(@rows); |
|
return $result if (! defined($data)); |
|
} |
|
return ''; |
|
} |
|
|
|
} # end of scope for &store_entry |
|
|
############################################################### |
############################################################### |
############################################################### |
############################################################### |