version 1.1, 2004/08/11 18:37:23
|
version 1.2, 2004/08/18 19:33:27
|
Line 55 use Getopt::Long();
|
Line 55 use Getopt::Long();
|
|
|
# |
# |
# Determine parameters |
# Determine parameters |
my ($help,$course,$domain,$drop,$file,$time_run,$nocleanup); |
my ($help,$course,$domain,$drop,$file,$time_run,$nocleanup,$log); |
&Getopt::Long::GetOptions( "course=s" => \$course, |
&Getopt::Long::GetOptions( "course=s" => \$course, |
"domain=s" => \$domain, |
"domain=s" => \$domain, |
"help" => \$help, |
"help" => \$help, |
"logfile=s" => \$file, |
"logfile=s" => \$file, |
"timerun" => \$time_run, |
"timerun" => \$time_run, |
"nocleanup" => \$nocleanup, |
"nocleanup" => \$nocleanup, |
"drop" => \$drop); |
"drop" => \$drop, |
|
"log" => \$log); |
if (! defined($course) || $help) { |
if (! defined($course) || $help) { |
print<<USAGE; |
print<<USAGE; |
parse_activity_log.pl |
parse_activity_log.pl |
Line 76 Parameters:
|
Line 77 Parameters:
|
file optional Specify the file to parse, including path |
file 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 |
Examples: |
Examples: |
$0 -course=123456abcdef -domain=msu |
$0 -course=123456abcdef -domain=msu |
$0 -course=123456abcdef -file=activity.log |
$0 -course=123456abcdef -file=activity.log |
Line 93 if ($time_run) {
|
Line 95 if ($time_run) {
|
my $initial_time = Time::HiRes::time; |
my $initial_time = Time::HiRes::time; |
|
|
## |
## |
|
## Set up logging code |
|
## |
|
my $logthis = \¬hing; |
|
if ($log) { |
|
my $logfile = "/tmp/parse_activity_log.log.".time; |
|
print STDERR "$0: logging to $logfile".$/; |
|
if (! open(LOGFILE,">$logfile")) { |
|
die "Unable to open $logfile for writing. Run aborted."; |
|
} else { |
|
$logthis = \&log_to_file; |
|
} |
|
} |
|
## |
## Read in configuration parameters |
## Read in configuration parameters |
## |
## |
my %perlvar; |
my %perlvar; |
Line 114 if ($file) {
|
Line 129 if ($file) {
|
$sourcefilename = &get_filename($course,$domain); |
$sourcefilename = &get_filename($course,$domain); |
} |
} |
$sql_filename = $sourcefilename; |
$sql_filename = $sourcefilename; |
$sql_filename =~ s|[^/]*$|activitylog.sql|; |
$sql_filename =~ s|[^/]*$|activity.log.sql|; |
|
|
## |
## |
## There will only be a $newfilename file if a copy of this program is already |
## There will only be a $newfilename file if a copy of this program is already |
Line 122 $sql_filename =~ s|[^/]*$|activitylog.sq
|
Line 137 $sql_filename =~ s|[^/]*$|activitylog.sq
|
my $newfilename = $sourcefilename.'.processing'; |
my $newfilename = $sourcefilename.'.processing'; |
if (-e $newfilename) { |
if (-e $newfilename) { |
warn "$newfilename exists"; |
warn "$newfilename exists"; |
|
$logthis->($newfilename.' exists'); |
exit 2; |
exit 2; |
} |
} |
|
|
if (-e $sourcefilename) { |
if (-e $sourcefilename) { |
rename($sourcefilename,$newfilename); |
rename($sourcefilename,$newfilename); |
|
$logthis->("renamed $sourcefilename to $newfilename"); |
} |
} |
|
|
## |
## |
Line 206 my $activity_table_def =
|
Line 223 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_id', |
type => 'VARCHAR(100) BINARY', |
type => 'MEDIUMINT UNSIGNED', |
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', }, |
Line 237 my @Activity_Tables = ($student_table_de
|
Line 254 my @Activity_Tables = ($student_table_de
|
$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."; |
|
$logthis->("Unable to connect to MySQL database."); |
exit 3; |
exit 3; |
} |
} |
|
|
if ($drop) { &drop_tables(); } |
if ($drop) { &drop_tables(); $logthis->('dropped tables'); } |
if (-e $sql_filename) { |
if (-e $sql_filename) { |
|
$logthis->('reading in from '.$sql_filename); |
# if ANY one of the tables does not exist, load the tables from the |
# if ANY one of the tables does not exist, load the tables from the |
# backup. |
# backup. |
my @Current_Tables = &Apache::lonmysql::tables_in_db(); |
my @Current_Tables = &Apache::lonmysql::tables_in_db(); |
Line 266 if (-e $sql_filename) {
|
Line 285 if (-e $sql_filename) {
|
# create_tables does not complain if the tables already exist |
# create_tables does not complain if the tables already exist |
if (! &create_tables()) { |
if (! &create_tables()) { |
warn "Unable to create tables"; |
warn "Unable to create tables"; |
|
$logthis->('Unable to create tables'); |
exit 4; |
exit 4; |
} |
} |
|
|
|
$logthis->('reading id tables'); |
&read_id_tables(); |
&read_id_tables(); |
|
$logthis->('finished reading id tables'); |
|
|
## |
## |
## Do the main bit of work |
## Do the main bit of work |
Line 277 if (-e $newfilename) {
|
Line 299 if (-e $newfilename) {
|
my $result = &process_courselog($newfilename); |
my $result = &process_courselog($newfilename); |
if (! defined($result)) { |
if (! defined($result)) { |
# Something went wrong along the way... |
# Something went wrong along the way... |
|
$logthis->('process_courselog returned undef'); |
exit 5; |
exit 5; |
} elsif ($result > 0) { |
} elsif ($result > 0) { |
$time_this->(); |
$time_this->(); |
|
$logthis->('process_courselog returned '.$result.' backup up tables'); |
&backup_tables($sql_filename); |
&backup_tables($sql_filename); |
$time_this->('write backup tables'); |
$time_this->('write backup tables'); |
} |
} |
Line 292 if (-e $newfilename) {
|
Line 316 if (-e $newfilename) {
|
unlink($newfilename) if (! $nocleanup); |
unlink($newfilename) if (! $nocleanup); |
|
|
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()); |
|
} |
|
|
|
if ($log) { |
|
close LOGFILE; |
} |
} |
|
|
exit 0; # Everything is okay, so end here before it gets worse. |
exit 0; # Everything is okay, so end here before it gets worse. |
Line 311 sub process_courselog {
|
Line 342 sub process_courselog {
|
my ($inputfile) = @_; |
my ($inputfile) = @_; |
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); |
Line 341 sub process_courselog {
|
Line 373 sub process_courselog {
|
$log = &unescape($log); |
$log = &unescape($log); |
$time_this->('translate_and_unescape'); |
$time_this->('translate_and_unescape'); |
# now go over all log entries |
# now go over all log entries |
|
if (! defined($host)) { $host = 'unknown'; } |
my $machine_id = &get_id($machine_table,'machine',$host); |
my $machine_id = &get_id($machine_table,'machine',$host); |
foreach (split(/\&\&\&/,$log)) { |
my $prevchunk = 'none'; |
|
foreach my $chunk (split(/\&\&\&/,$log)) { |
|
my $warningflag = ''; |
$time_this->(); |
$time_this->(); |
my ($time,$res,$uname,$udom,$action,@values)= split(/:/,$_); |
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 = 'log in'; |
$action = 'LOGIN'; |
|
# $warningflag .= 'res'; |
} |
} |
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'; |
|
# $warningflag .= 'action'; |
} |
} |
my $student = $uname.':'.$udom; |
if ($action !~ /^(LOGIN|VIEW|POST|CSTORE|STORE)$/) { |
|
$warningflag .= 'action'; |
|
} |
|
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'); |
$time_this->('split_and_error_check'); |
my $student_id = &get_id($student_table,'student',$student); |
my $student_id = &get_id($student_table,'student',$student); |
my $res_id = &get_id($res_table,'resource',$res); |
my $res_id = &get_id($res_table,'resource',$res); |
my $action_id = &get_id($action_table,'action',$action); |
my $action_id = &get_id($action_table,'action',$action); |
my $sql_time = &Apache::lonmysql::sqltime($time); |
my $sql_time = &Apache::lonmysql::sqltime($time); |
|
# |
|
if (! defined($student_id) || $student_id eq '') { |
|
$warningflag.='student_id'; |
|
} |
|
if (! defined($res_id) || $res_id eq '') { |
|
$warningflag.='res_id'; |
|
} |
|
if (! defined($action_id) || $action_id eq '') { |
|
$warningflag.='action_id'; |
|
} |
|
if ($warningflag ne '') { |
|
$logthis->('warningflag ('.$warningflag.') on chunk '. |
|
$/.$chunk.$/.'prevchunk = '.$/.$prevchunk); |
|
$prevchunk .= $chunk; |
|
next; # skip this chunk |
|
} |
|
# |
my $values = $dbh->quote(join('',@values)); |
my $values = $dbh->quote(join('',@values)); |
$time_this->('get_ids'); |
$time_this->('get_ids'); |
# |
# |
Line 373 sub process_courselog {
|
Line 447 sub process_courselog {
|
$values]; |
$values]; |
push(@RowData,$row); |
push(@RowData,$row); |
$time_this->('push_row'); |
$time_this->('push_row'); |
|
$prevchunk = $chunk; |
# |
# |
} |
} |
$time_this->(); |
$time_this->(); |
if ($linecount % 100 == 0) { |
if ((scalar(@RowData) > 0) && ($linecount % 100 == 0)) { |
my $result = &Apache::lonmysql::bulk_store_rows($activity_table, |
my $result = &Apache::lonmysql::bulk_store_rows($activity_table, |
undef, |
undef, |
\@RowData); |
\@RowData); |
|
# $logthis->('result = '.$result); |
$time_this->('bulk_store_rows'); |
$time_this->('bulk_store_rows'); |
if (! defined($result)) { |
if (! defined($result)) { |
warn "Error occured during insert.". |
my $error = &Apache::lonmysql::get_error(); |
&Apache::lonmysql::get_error(); |
warn "Error occured during insert.".$error; |
|
$logthis->('error = '.$error); |
} |
} |
undef(@RowData); |
undef(@RowData); |
} |
} |
} |
} |
if (@RowData) { |
if (@RowData) { |
$time_this->(); |
$time_this->(); |
|
$logthis->('storing '.$linecount); |
my $result = &Apache::lonmysql::bulk_store_rows($activity_table, |
my $result = &Apache::lonmysql::bulk_store_rows($activity_table, |
undef, |
undef, |
\@RowData); |
\@RowData); |
|
$logthis->('result = '.$result); |
$time_this->('bulk_store_rows'); |
$time_this->('bulk_store_rows'); |
if (! defined($result)) { |
if (! defined($result)) { |
warn "Error occured during insert.". |
my $error = &Apache::lonmysql::get_error(); |
&Apache::lonmysql::get_error(); |
warn "Error occured during insert.".$error; |
|
$logthis->('error = '.$error); |
} |
} |
undef(@RowData); |
undef(@RowData); |
} |
} |
Line 406 sub process_courselog {
|
Line 486 sub process_courselog {
|
return $linecount; |
return $linecount; |
} |
} |
|
|
|
|
|
## |
|
## Somtimes, instead of doing something, doing nothing is appropriate. |
|
sub nothing { |
|
return; |
|
} |
|
|
|
## |
|
## Logging routine |
|
## |
|
sub log_to_file { |
|
my ($input)=@_; |
|
print LOGFILE $input.$/; |
|
} |
|
|
## |
## |
## Timing routines |
## Timing routines |
## |
## |
Line 413 sub process_courselog {
|
Line 508 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 457 sub backup_tables {
|
Line 548 sub backup_tables {
|
$command .= $tablename.' '; |
$command .= $tablename.' '; |
} |
} |
$command .= '>'.$sql_filename; |
$command .= '>'.$sql_filename; |
warn $command.$/; |
$logthis->($command); |
system($command); |
system($command); |
} |
} |
|
|
Line 469 sub load_backup_tables {
|
Line 560 sub load_backup_tables {
|
return undef if (! -e $sql_filename); |
return undef if (! -e $sql_filename); |
# Check for .my.cnf |
# Check for .my.cnf |
my $command = 'mysql -e "SOURCE '.$sql_filename.'" loncapa'; |
my $command = 'mysql -e "SOURCE '.$sql_filename.'" loncapa'; |
warn $command.$/; |
$logthis->('loading previously saved sql table'.$/.$command); |
system($command); |
system($command); |
} |
} |
|
|
Line 551 sub get_id {
|
Line 642 sub get_id {
|
$IDs{$table}->{$value}=$Data[0]->[0]; |
$IDs{$table}->{$value}=$Data[0]->[0]; |
return $IDs{$table}->{$value}; |
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 578 sub unescape {
|
Line 669 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; |
} |
} |
|
|