version 1.1, 2004/08/11 18:37:23
|
version 1.25, 2014/11/24 02:36:34
|
Line 26
|
Line 26
|
# |
# |
# http://www.lon-capa.org/ |
# http://www.lon-capa.org/ |
# |
# |
############################################################################### |
#-------------------------------------------------------------------- |
# |
|
# Expects |
|
# |
|
# ../key/$class.key - key file $username:$keynumber |
|
# ../rawdata/$class.log - log file |
|
# ../rawdata/$class.seq - sequence file |
|
# ../data writable |
|
# ------------------------------------------------------------------ Course log |
|
|
|
# |
# |
# Exit codes |
# Exit codes |
# 0 Everything is okay |
# 0 Everything is okay |
Line 43
|
Line 34
|
# 2 Activity log does not exist |
# 2 Activity log does not exist |
# 3 Unable to connect to database |
# 3 Unable to connect to database |
# 4 Unable to create database tables |
# 4 Unable to create database tables |
# 5 Unspecified error? |
# 5 Unable to open log file |
|
# 6 Unable to get lock on activity log |
# |
# |
|
|
|
# |
|
# Notes: |
|
# |
|
# Logging is done via the $logthis variable, which may be the result of |
|
# overcleverness. log via $logthis->('logtext'); Those are parentheses, |
|
# not curly braces. If the -log command line parameter is set, the $logthis |
|
# routine is set to a routine which writes to a file. If the command line |
|
# parameter is not set $logthis is set to ¬hing, which does what you |
|
# would expect. |
|
# |
use strict; |
use strict; |
use DBI; |
use DBI; |
use lib '/home/httpd/lib/perl/Apache'; |
use lib '/home/httpd/lib/perl/'; |
use lonmysql(); |
use LONCAPA::Configuration(); |
|
use Apache::lonmysql(); |
use Time::HiRes(); |
use Time::HiRes(); |
use Getopt::Long(); |
use Getopt::Long(); |
|
use IO::File; |
|
use File::Copy; |
|
use Fcntl qw(:flock); |
|
use HTML::TokeParser; |
|
|
# |
# |
# Determine parameters |
# Determine parameters |
my ($help,$course,$domain,$drop,$file,$time_run,$nocleanup); |
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, |
"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); |
if (! defined($course) || $help) { |
if (! defined($course) || $help) { |
print<<USAGE; |
print<<USAGE; |
parse_activity_log.pl |
parse_activity_log.pl |
Line 70 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 |
drop optional if present, drop all course |
backup optional if present, backup the activity log file |
specific activity log tables. |
before processing it |
file optional Specify the file to parse, including path |
dropwhendone optional if present, drop all course |
|
specific activity log tables after processing. |
|
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 |
|
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; |
} |
} |
|
|
## |
## |
## Set up timing code |
## Set up timing code |
## |
|
my $time_this = \¬hing; |
my $time_this = \¬hing; |
if ($time_run) { |
if ($time_run) { |
$time_this = \&time_action; |
$time_this = \&time_action; |
Line 95 my $initial_time = Time::HiRes::time;
|
Line 110 my $initial_time = Time::HiRes::time;
|
## |
## |
## Read in configuration parameters |
## Read in configuration parameters |
## |
## |
my %perlvar; |
my %perlvar = %{&LONCAPA::Configuration::read_conf('loncapa.conf')}; |
&initialize_configuration(); |
|
if (! defined($domain) || $domain eq '') { |
if (! defined($domain) || $domain eq '') { |
$domain = $perlvar{'lonDefDomain'}; |
$domain = $perlvar{'lonDefDomain'}; |
} |
} |
&update_process_name($course.'@'.$domain); |
&update_process_name($course.'@'.$domain); |
|
|
## |
## |
|
## Set up logging code |
|
my $logthis = \¬hing; |
|
|
|
if ($log) { |
|
if (! $logfile) { |
|
$logfile = $perlvar{'lonDaemons'}.'/tmp/parse_activity_log.log.'.time; |
|
} |
|
print STDERR "$0: logging to $logfile".$/; |
|
if (! open(LOGFILE,">$logfile")) { |
|
warn("Unable to open $logfile for writing. Run aborted."); |
|
&clean_up_and_exit(5); |
|
} else { |
|
$logthis = \&log_to_file; |
|
} |
|
} |
|
|
|
|
|
## |
## Determine filenames |
## Determine filenames |
## |
## |
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 $sql_filename; # the mysql backup data file name. |
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); |
} |
} |
$sql_filename = $sourcefilename; |
my $sql_filename = $sourcefilename; |
$sql_filename =~ s|[^/]*$|activitylog.sql|; |
$sql_filename =~ s|[^/]*$|activity.log.sql|; |
|
my $gz_sql_filename = $sql_filename.'.gz'; |
## |
# |
## There will only be a $newfilename file if a copy of this program is already |
$chunk_filename = $sourcefilename.".unprocessed_chunks"; |
## running. |
# |
my $newfilename = $sourcefilename.'.processing'; |
my $xml_filename = $sourcefilename; |
if (-e $newfilename) { |
my $gz_xml_filename = $xml_filename.'.gz'; |
warn "$newfilename exists"; |
if (defined($xmlfile)) { |
exit 2; |
$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 =~ s|[^/]*$|activity.log.errors|; |
|
$logthis->('Beginning logging '.time); |
|
|
if (-e $sourcefilename) { |
# |
rename($sourcefilename,$newfilename); |
# Wait for a lock on the lockfile to avoid collisions |
|
my $lockfilename = $sourcefilename.'.lock'; |
|
$newfilename = $sourcefilename.'.processing'; |
|
if (! defined($xmlfile)) { |
|
open(LOCKFILE,'>'.$lockfilename); |
|
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 |
|
exit 6; |
|
} |
|
|
|
if (! -e $newfilename && -e $sourcefilename) { |
|
$logthis->('renaming '.$sourcefilename.' to '.$newfilename); |
|
rename($sourcefilename,$newfilename); |
|
Copy($newfilename,$newfilename.'.'.time) if ($backup); |
|
$logthis->("renamed $sourcefilename to $newfilename"); |
|
} elsif (! -e $newfilename) { |
|
utime(undef,undef,$newfilename); |
|
} |
} |
} |
|
|
## |
## |
## 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 149 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 164 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', |
# columns => [{ name => 'action_id', |
columns => [{ name => 'action_id', |
# type => 'MEDIUMINT UNSIGNED', |
type => 'MEDIUMINT UNSIGNED', |
# restrictions => 'NOT NULL', |
restrictions => 'NOT NULL', |
# auto_inc => 'yes', }, |
auto_inc => 'yes', }, |
# { name => 'action', |
{ name => 'action', |
# type => 'VARCHAR(100)', |
type => 'VARCHAR(100)', |
# restrictions => 'NOT NULL'}, |
restrictions => 'NOT NULL'}, |
# ], |
], |
# '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 194 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 206 my $activity_table_def =
|
Line 267 my $activity_table_def =
|
type => 'DATETIME', |
type => 'DATETIME', |
restrictions => 'NOT NULL',}, |
restrictions => 'NOT NULL',}, |
{ name => 'student_id', |
{ name => 'student_id', |
type => 'VARCHAR(100) BINARY', |
type => 'MEDIUMINT UNSIGNED', |
restrictions => 'NOT NULL',}, |
restrictions => 'NOT NULL',}, |
{ name => 'action_id', |
{ name => 'action', |
type => 'VARCHAR(100) BINARY', |
type => 'VARCHAR(10)', |
restrictions => 'NOT NULL',}, |
restrictions => 'NOT NULL',}, |
{ name => 'idx', # This is here in case a student |
{ name => 'idx', # This is here in case a student |
type => 'MEDIUMINT UNSIGNED', # has multiple submissions during |
type => 'MEDIUMINT UNSIGNED', # has multiple submissions during |
restrictions => 'NOT NULL', # one second. It happens, trust |
restrictions => 'NOT NULL', # one second. It happens, trust |
auto_inc => 'yes', }, # me. |
auto_inc => 'yes', }, # me. |
{ name => 'machine_id', |
{ name => 'machine_id', |
type => 'VARCHAR(100) BINARY', |
type => 'MEDIUMINT UNSIGNED', |
restrictions => 'NOT NULL',}, |
restrictions => 'NOT NULL',}, |
{ name => 'action_values', |
{ name => 'action_values', |
type => 'MEDIUMTEXT', }, |
type => 'MEDIUMTEXT', }, |
], |
], |
'PRIMARY KEY' => ['res_id','time','student_id','action_id','idx'], |
'PRIMARY KEY' => ['time','student_id','res_id','idx'], |
|
'KEY' => [{columns => ['student_id']}, |
|
{columns => ['time']},], |
}; |
}; |
my @Activity_Tables = ($student_table_def,$res_table_def, |
|
$action_table_def,$machine_table_def, |
|
$activity_table_def); |
|
|
|
|
|
|
my @Activity_Table = ($activity_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'); |
&Apache::lonmysql::set_mysql_user_and_password($perlvar{'lonSqlUser'}, |
&Apache::lonmysql::set_mysql_user_and_password('www', |
$perlvar{'lonSqlAccess'}); |
$perlvar{'lonSqlAccess'}); |
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."; |
exit 3; |
$logthis->("Unable to connect to MySQL database."); |
|
&clean_up_and_exit(3); |
} |
} |
|
$logthis->('SQL connection is up'); |
|
|
if ($drop) { &drop_tables(); } |
&update_process_name($course.'@'.$domain." loading existing data"); |
if (-e $sql_filename) { |
my $missing_table = &check_for_missing_tables(values(%tables)); |
# if ANY one of the tables does not exist, load the tables from the |
if (-s $gz_sql_filename && ! -s $gz_xml_filename) { |
# backup. |
my $backup_modification_time = (stat($gz_sql_filename))[9]; |
my @Current_Tables = &Apache::lonmysql::tables_in_db(); |
$logthis->($gz_sql_filename.' was last modified '. |
my %Found; |
localtime($backup_modification_time). |
foreach my $tablename (@Current_Tables) { |
'('.$backup_modification_time.')'); |
foreach my $table (@Activity_Tables) { |
if ($missing_table) { |
if ($tablename eq $table->{'id'}) { |
# If the backup happened prior to the last table modification, |
$Found{$tablename}++; |
# we need to save the tables. |
} |
if (&latest_table_modification_time() > $backup_modification_time) { |
|
# Save the current tables in case we need them another time. |
|
$logthis->('Backing existing tables up'); |
|
&backup_tables_as_xml($gz_xml_filename.'.save_'.time,\%tables); |
} |
} |
} |
$time_this->(); |
foreach my $table (@Activity_Tables) { |
&load_backup_sql_tables($gz_sql_filename); |
if (! $Found{$table->{'id'}}) { |
&backup_tables_as_xml($gz_xml_filename,\%tables); |
$time_this->(); |
$time_this->('load backup tables'); |
&load_backup_tables($sql_filename); |
} |
$time_this->('load backup tables'); |
} elsif (-s $gz_xml_filename) { |
last; |
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; |
|
# If the backup happened prior to the last table modification, |
|
# we need to save the tables. |
|
if (&latest_table_modification_time() > $backup_modification_time) { |
|
# Save the current tables in case we need them another time. |
|
$logthis->('Backing existing tables up'); |
|
&backup_tables_as_xml($gz_xml_filename.'.save_'.time,\%tables); |
} |
} |
} |
$time_this->(); |
|
# 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'); |
|
} |
|
} |
|
|
|
if (defined($xmlfile)) { |
|
&clean_up_and_exit(0); |
} |
} |
|
|
|
## |
|
## 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 |
|
$logthis->('creating tables'); |
if (! &create_tables()) { |
if (! &create_tables()) { |
warn "Unable to create tables"; |
warn "Unable to create tables"; |
exit 4; |
$logthis->('Unable to create tables'); |
|
&clean_up_and_exit(4); |
} |
} |
|
|
|
## |
|
## Read the ids used for various tables |
|
$logthis->('reading id tables'); |
&read_id_tables(); |
&read_id_tables(); |
|
$logthis->('finished reading id tables'); |
|
|
|
## |
|
## Set up the errors file |
|
my $error_fh = IO::File->new(">>$error_filename"); |
|
|
## |
## |
## Do the main bit of work |
## Parse the course log |
if (-e $newfilename) { |
$logthis->('processing course log'); |
my $result = &process_courselog($newfilename); |
&update_process_name($course.'@'.$domain." processing new data"); |
|
if (-s $newfilename) { |
|
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... |
exit 5; |
$logthis->('process_courselog returned undef'); |
|
&clean_up_and_exit(5); |
} elsif ($result > 0) { |
} elsif ($result > 0) { |
$time_this->(); |
$time_this->(); |
&backup_tables($sql_filename); |
$logthis->('process_courselog returned '.$result.'.'.$/. |
|
'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); |
|
|
## |
## |
## Clean up the filesystem |
## Clean up the filesystem |
## |
|
&Apache::lonmysql::disconnect_from_db(); |
&Apache::lonmysql::disconnect_from_db(); |
unlink($newfilename) if (! $nocleanup); |
unlink($newfilename) if (-e $newfilename && ! $nocleanup); |
|
|
|
## |
|
## Print timing data |
|
$logthis->('printing timing data'); |
if ($time_run) { |
if ($time_run) { |
print "Overall time: ".(Time::HiRes::time - $initial_time).$/; |
my $elapsed_time = Time::HiRes::time - $initial_time; |
|
print "Overall time: ".$elapsed_time.$/; |
print &outputtimes(); |
print &outputtimes(); |
|
$logthis->("Overall time: ".$elapsed_time); |
|
$logthis->(&outputtimes()); |
} |
} |
|
|
exit 0; # Everything is okay, so end here before it gets worse. |
&clean_up_and_exit(0); |
|
|
|
######################################################## |
|
######################################################## |
|
|
|
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; |
|
} |
|
|
|
######################################################## |
|
######################################################## |
|
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 308 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) = @_; |
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"); |
return undef; |
return undef; |
} |
} |
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 327 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 335 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 |
my $machine_id = &get_id($machine_table,'machine',$host); |
if (! defined($host)) { $host = 'unknown'; } |
foreach (split(/\&\&\&/,$log)) { |
my $prevchunk = 'none'; |
$time_this->(); |
foreach my $chunk (split(/\&\&\&/,$log)) { |
my ($time,$res,$uname,$udom,$action,@values)= split(/:/,$_); |
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 ($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 = 'log in'; |
$action = 'LOGIN'; |
} |
} |
if ($res =~ m|^/prtspool/|) { |
if ($res =~ m|^/prtspool/|) { |
$res = '/prtspool/'; |
$res = '/prtspool/'; |
} |
} |
if (! defined($action) || $action eq '') { |
if (! defined($action) || $action eq '') { |
$action = 'view'; |
$action = 'VIEW'; |
|
} |
|
if ($action !~ /^(LOGIN|VIEW|POST|CSTORE|STORE|PUTSTORE)$/) { |
|
$warningflag .= 'action'; |
|
print $error_fh 'full log entry:'.$log.$/; |
|
print $error_fh 'error on chunk (saving)'.$/; |
|
if (! &savechunk(\$chunk,$timestamp,$host)) { |
|
close(IN); |
|
return undef; |
|
} |
|
$logthis->('(action) Unable to parse chunk'.$/. |
|
'got '. |
|
'time = '.$time.$/. |
|
'res = '.$res.$/. |
|
'uname= '.$uname.$/. |
|
'udom = '.$udom.$/. |
|
'action='.$action.$/. |
|
'@values = '.join('&',@values)); |
|
next; #skip it if we cannot understand what is happening. |
} |
} |
my $student = $uname.':'.$udom; |
|
$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); |
|
my $values = $dbh->quote(join('',@values)); |
|
$time_this->('get_ids'); |
|
# |
|
my $row = [$res_id, |
|
qq{'$sql_time'}, |
|
$student_id, |
|
$action_id, |
|
qq{''}, # idx |
|
$machine_id, |
|
$values]; |
|
push(@RowData,$row); |
|
$time_this->('push_row'); |
|
# |
# |
} |
my %data = (student => $uname.':'.$udom, |
$time_this->(); |
resource => $res, |
if ($linecount % 100 == 0) { |
machine => $host, |
my $result = &Apache::lonmysql::bulk_store_rows($activity_table, |
action => $action, |
undef, |
time => &Apache::lonmysql::sqltime($time)); |
\@RowData); |
if ($action eq 'POST') { |
$time_this->('bulk_store_rows'); |
$data{'action_values'} = |
if (! defined($result)) { |
$dbh->quote(join('&',map { &escape($_); } @values)); |
warn "Error occured during insert.". |
} else { |
&Apache::lonmysql::get_error(); |
$data{'action_values'} = $dbh->quote(join('&',@values)); |
} |
} |
undef(@RowData); |
my $error = &store_entry($dbh,$tables,\%data); |
|
if ($error) { |
|
$logthis->('error store_entry:'.$error." on %data"); |
|
} |
|
$prevchunk = $chunk; |
} |
} |
} |
} |
if (@RowData) { |
my $result = &store_entry($dbh,$tables); |
$time_this->(); |
if (! defined($result)) { |
my $result = &Apache::lonmysql::bulk_store_rows($activity_table, |
my $error = &Apache::lonmysql::get_error(); |
undef, |
warn "Error occured during insert.".$error; |
\@RowData); |
$logthis->('error = '.$error); |
$time_this->('bulk_store_rows'); |
|
if (! defined($result)) { |
|
warn "Error occured during insert.". |
|
&Apache::lonmysql::get_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; |
|
} |
|
} |
|
|
|
|
|
## |
|
## default value for $logthis and $time_this |
|
sub nothing { |
|
return; |
|
} |
|
|
|
## |
|
## Logging routine (look for $log) |
|
## |
|
sub log_to_file { |
|
my ($input)=@_; |
|
print LOGFILE $input.$/; |
} |
} |
|
|
## |
## |
Line 413 sub process_courselog {
|
Line 596 sub process_courselog {
|
my %Timing; |
my %Timing; |
my $starttime; |
my $starttime; |
|
|
sub nothing { |
|
return; |
|
} |
|
|
|
sub time_action { |
sub time_action { |
my ($key) = @_; |
my ($key) = @_; |
if (defined($key)) { |
if (defined($key)) { |
Line 444 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 ($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 (@Activity_Tables) { |
|
my $tablename = $table->{'id'}; |
my $tablename = $table->{'id'}; |
|
$tablename =~ s/\`//g; |
$command .= $tablename.' '; |
$command .= $tablename.' '; |
} |
} |
$command .= '>'.$sql_filename; |
$command .= '| gzip >'.$gz_sql_filename; |
warn $command.$/; |
$logthis->($command); |
system($command); |
system($command); |
} |
} |
|
|
## |
## |
## Load in mysqldumped files |
## Load in mysqldumped files |
## |
## |
sub load_backup_tables { |
sub load_backup_sql_tables { |
my ($sql_filename) = @_; |
my ($gz_sql_filename) = @_; |
return undef if (! -e $sql_filename); |
if (-s $gz_sql_filename) { |
# Check for .my.cnf |
$logthis->('loading data from gzipped sql file'); |
my $command = 'mysql -e "SOURCE '.$sql_filename.'" loncapa'; |
my $command='gzip -dc '.$gz_sql_filename.' | mysql --database=loncapa'; |
warn $command.$/; |
system($command); |
system($command); |
$logthis->('finished loading gzipped data');; |
|
} else { |
|
return undef; |
|
} |
} |
} |
|
|
## |
## |
## |
## |
## |
## |
sub initialize_configuration { |
|
# Fake it for now: |
|
$perlvar{'lonSqlUser'} = 'www'; |
|
$perlvar{'lonSqlAccess'} = 'localhostkey'; |
|
$perlvar{'lonUsersDir'} = '/home/httpd/lonUsers'; |
|
$perlvar{'lonDefDomain'} = '103'; |
|
} |
|
|
|
sub update_process_name { |
sub update_process_name { |
my ($text) = @_; |
my ($text) = @_; |
$0 = 'parse_activity_log.pl: '.$text; |
$0 = 'parse_activity_log.pl: '.$text; |
Line 496 sub get_filename {
|
Line 706 sub get_filename {
|
} |
} |
|
|
sub create_tables { |
sub create_tables { |
foreach my $table (@Activity_Tables) { |
foreach my $table (@ID_Tables,@Activity_Table) { |
my $table_id = &Apache::lonmysql::create_table($table); |
my $table_id = &Apache::lonmysql::create_table($table); |
if (! defined($table_id)) { |
if (! defined($table_id)) { |
warn "Unable to create table ".$table->{'id'}.$/; |
warn "Unable to create table ".$table->{'id'}.$/; |
warn &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 508 sub create_tables {
|
Line 719 sub create_tables {
|
} |
} |
|
|
sub drop_tables { |
sub drop_tables { |
foreach my $table (@Activity_Tables) { |
foreach my $table (@ID_Tables,@Activity_Table) { |
my $table_id = $table->{'id'}; |
my $table_id = $table->{'id'}; |
&Apache::lonmysql::drop_table($table_id); |
&Apache::lonmysql::drop_table($table_id); |
} |
} |
Line 525 sub drop_tables {
|
Line 736 sub drop_tables {
|
my %IDs; |
my %IDs; |
|
|
sub read_id_tables { |
sub read_id_tables { |
foreach my $table (@Activity_Tables) { |
foreach my $table (@ID_Tables) { |
my @Data = &Apache::lonmysql::get_rows($table->{'id'}); |
my @Data = &Apache::lonmysql::get_rows($table->{'id'}); |
|
my $count = 0; |
foreach my $row (@Data) { |
foreach my $row (@Data) { |
$IDs{$table->{'id'}}->{$row->[1]} = $row->[0]; |
$IDs{$table->{'id'}}->{$row->[1]} = $row->[0]; |
} |
} |
} |
} |
|
return; |
} |
} |
|
|
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 { |
warn "Unable to retrieve id for $table $fieldname $value".$/; |
$logthis->("Unable to retrieve id for $table $fieldname $value"); |
return undef; |
return undef; |
} |
} |
} |
} |
Line 559 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 |
|
|
############################################################### |
############################################################### |
############################################################### |
############################################################### |
Line 578 sub unescape {
|
Line 1019 sub unescape {
|
$str =~ s/%([a-fA-F0-9][a-fA-F0-9])/pack("C",hex($1))/eg; |
$str =~ s/%([a-fA-F0-9][a-fA-F0-9])/pack("C",hex($1))/eg; |
return $str; |
return $str; |
} |
} |
|
|