loncom/metadata_database/parse_activity_log.pl - view

File: [LON-CAPA] / loncom / metadata_database / parse_activity_log.pl
Revision 1.25: download - view: text, annotated - select for diffs
Mon Nov 24 02:36:34 2014 UTC (9 years, 5 months ago) by raeburn
Branches: MAIN
CVS tags: version_2_12_X, version_2_11_X, version_2_11_4_uiuc, version_2_11_4_msu, version_2_11_4, version_2_11_3_uiuc, version_2_11_3_msu, version_2_11_3, version_2_11_2_uiuc, version_2_11_2_msu, version_2_11_2_educog, version_2_11_2, version_2_11_1, HEAD

- Bug 6740 Out-of-order recording of submissions (by time).
  - Check for new transactions made immediately before call to lonnet::cstore()
    &Apache::inputtags::hidealldata() called if correct then incorrect,
    where awarded >= 1 when correct (feedback on correctness enabled).
  - Check for transactions made immediately after call to lonnet::cstore()
    if reply from lond::store_handler() is delay:N (where N s the number of
    transactions between the last retrieved in &initialize_storage() and the
    last stored immediately before permanent storage of the current transaction.
    &Apache::grades::makehidden() called if correct then incorrect,
    where awarded >= 1 when correct (feedback on correctness enabled).

1: #!/usr/bin/perl 2: # 3: # The LearningOnline Network 4: # 5: # $Id: parse_activity_log.pl,v 1.25 2014/11/24 02:36:34 raeburn Exp $ 6: # 7: # Copyright Michigan State University Board of Trustees 8: # 9: # This file is part of the LearningOnline Network with CAPA (LON-CAPA). 10: # 11: # LON-CAPA is free software; you can redistribute it and/or modify 12: # it under the terms of the GNU General Public License as published by 13: # the Free Software Foundation; either version 2 of the License, or 14: # (at your option) any later version. 15: # 16: # LON-CAPA is distributed in the hope that it will be useful, 17: # but WITHOUT ANY WARRANTY; without even the implied warranty of 18: # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the 19: # GNU General Public License for more details. 20: # 21: # You should have received a copy of the GNU General Public License 22: # along with LON-CAPA; if not, write to the Free Software 23: # Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA 24: # 25: # /home/httpd/html/adm/gpl.txt 26: # 27: # http://www.lon-capa.org/ 28: # 29: #-------------------------------------------------------------------- 30: # 31: # Exit codes 32: # 0 Everything is okay 33: # 1 Another copy is running on this course 34: # 2 Activity log does not exist 35: # 3 Unable to connect to database 36: # 4 Unable to create database tables 37: # 5 Unable to open log file 38: # 6 Unable to get lock on activity log 39: # 40: 41: # 42: # Notes: 43: # 44: # Logging is done via the $logthis variable, which may be the result of 45: # overcleverness. log via $logthis->('logtext'); Those are parentheses, 46: # not curly braces. If the -log command line parameter is set, the $logthis 47: # routine is set to a routine which writes to a file. If the command line 48: # parameter is not set $logthis is set to &nothing, which does what you 49: # would expect. 50: # 51: use strict; 52: use DBI; 53: use lib '/home/httpd/lib/perl/'; 54: use LONCAPA::Configuration(); 55: use Apache::lonmysql(); 56: use Time::HiRes(); 57: use Getopt::Long(); 58: use IO::File; 59: use File::Copy; 60: use Fcntl qw(:flock); 61: use HTML::TokeParser; 62: 63: # 64: # Determine parameters 65: my ($help,$course,$domain,$drop_when_done,$srcfile,$logfile,$time_run,$nocleanup,$log,$backup,$xmlfile); 66: &Getopt::Long::GetOptions( "course=s" => \$course, 67: "domain=s" => \$domain, 68: "backup" => \$backup, 69: "help" => \$help, 70: "logfile=s" => \$logfile, 71: "srcfile=s" => \$srcfile, 72: "justloadxml=s" => \$xmlfile, 73: "timerun" => \$time_run, 74: "nocleanup" => \$nocleanup, 75: "dropwhendone" => \$drop_when_done, 76: "log" => \$log); 77: if (! defined($course) || $help) { 78: print<<USAGE; 79: parse_activity_log.pl 80: 81: Process a lon-capa activity log into a database. 82: Parameters: 83: course Required 84: domain optional 85: backup optional if present, backup the activity log file 86: before processing it 87: dropwhendone optional if present, drop all course 88: specific activity log tables after processing. 89: srcfile optional Specify the file to parse, including path 90: time optional if present, print out timing data 91: nocleanup optional if present, do not remove old files 92: log optional if present, prepare log file of activity 93: logfile optional specifies the logfile to use 94: Examples: 95: $0 -course=123456abcdef -domain=msu 96: $0 -course=123456abcdef -srcfile=activity.log 97: $0 -course-123456abcdef -log -logfile=/tmp/logfile -dropwhendone 98: USAGE 99: exit; 100: } 101: 102: ## 103: ## Set up timing code 104: my $time_this = \&nothing; 105: if ($time_run) { 106: $time_this = \&time_action; 107: } 108: my $initial_time = Time::HiRes::time; 109: 110: ## 111: ## Read in configuration parameters 112: ## 113: my %perlvar = %{&LONCAPA::Configuration::read_conf('loncapa.conf')}; 114: 115: if (! defined($domain) || $domain eq '') { 116: $domain = $perlvar{'lonDefDomain'}; 117: } 118: &update_process_name($course.'@'.$domain); 119: 120: ## 121: ## Set up logging code 122: my $logthis = \&nothing; 123: 124: if ($log) { 125: if (! $logfile) { 126: $logfile = $perlvar{'lonDaemons'}.'/tmp/parse_activity_log.log.'.time; 127: } 128: print STDERR "$0: logging to $logfile".$/; 129: if (! open(LOGFILE,">$logfile")) { 130: warn("Unable to open $logfile for writing. Run aborted."); 131: &clean_up_and_exit(5); 132: } else { 133: $logthis = \&log_to_file; 134: } 135: } 136: 137: 138: ## 139: ## Determine filenames 140: ## 141: my $sourcefilename; # activity log data 142: my $newfilename; # $sourcefilename will be renamed to this 143: my $error_filename; # Errors in parsing the activity log will be written here 144: my $chunk_filename; # where we save data we are not going to write to db 145: if ($srcfile) { 146: $sourcefilename = $srcfile; 147: } else { 148: $sourcefilename = &get_filename($course,$domain); 149: } 150: my $sql_filename = $sourcefilename; 151: $sql_filename =~ s|[^/]*$|activity.log.sql|; 152: my $gz_sql_filename = $sql_filename.'.gz'; 153: # 154: $chunk_filename = $sourcefilename.".unprocessed_chunks"; 155: # 156: my $xml_filename = $sourcefilename; 157: my $gz_xml_filename = $xml_filename.'.gz'; 158: if (defined($xmlfile)) { 159: $xml_filename = $xmlfile; 160: if ($xml_filename =~ /\.gz$/) { 161: $gz_xml_filename = $xml_filename; 162: } else { 163: $gz_xml_filename = $xml_filename.'.gz'; 164: } 165: } else { 166: my $xml_filename = $sourcefilename; 167: $xml_filename =~ s|[^/]*$|activity.log.xml|; 168: $gz_xml_filename = $xml_filename.'.gz'; 169: } 170: # 171: $error_filename = $sourcefilename; 172: $error_filename =~ s|[^/]*$|activity.log.errors|; 173: $logthis->('Beginning logging '.time); 174: 175: # 176: # Wait for a lock on the lockfile to avoid collisions 177: my $lockfilename = $sourcefilename.'.lock'; 178: $newfilename = $sourcefilename.'.processing'; 179: if (! defined($xmlfile)) { 180: open(LOCKFILE,'>'.$lockfilename); 181: if (!flock(LOCKFILE,LOCK_EX|LOCK_NB)) { 182: warn("Unable to lock $lockfilename. Aborting".$/); 183: # don't call clean_up_and_exit another instance is running and 184: # we don't want to 'cleanup' their files 185: exit 6; 186: } 187: 188: if (! -e $newfilename && -e $sourcefilename) { 189: $logthis->('renaming '.$sourcefilename.' to '.$newfilename); 190: rename($sourcefilename,$newfilename); 191: Copy($newfilename,$newfilename.'.'.time) if ($backup); 192: $logthis->("renamed $sourcefilename to $newfilename"); 193: } elsif (! -e $newfilename) { 194: utime(undef,undef,$newfilename); 195: } 196: } 197: 198: ## 199: ## Table definitions 200: ## 201: my %tables = &table_names($course,$domain); 202: my $student_table_def = 203: { id => $tables{'student'}, 204: permanent => 'no', 205: columns => [ 206: { name => 'student_id', 207: type => 'MEDIUMINT UNSIGNED', 208: restrictions => 'NOT NULL', 209: auto_inc => 'yes', }, 210: { name => 'student', 211: type => 'VARCHAR(100) BINARY', 212: restrictions => 'NOT NULL', }, 213: ], 214: 'PRIMARY KEY' => ['student_id',], 215: }; 216: 217: my $res_table_def = 218: { id => $tables{'res'}, 219: permanent => 'no', 220: columns => [{ name => 'res_id', 221: type => 'MEDIUMINT UNSIGNED', 222: restrictions => 'NOT NULL', 223: auto_inc => 'yes', }, 224: { name => 'resource', 225: type => 'MEDIUMTEXT', 226: restrictions => 'NOT NULL'}, 227: ], 228: 'PRIMARY KEY' => ['res_id'], 229: }; 230: 231: #my $action_table_def = 232: #{ id => $action_table, 233: # permanent => 'no', 234: # columns => [{ name => 'action_id', 235: # type => 'MEDIUMINT UNSIGNED', 236: # restrictions => 'NOT NULL', 237: # auto_inc => 'yes', }, 238: # { name => 'action', 239: # type => 'VARCHAR(100)', 240: # restrictions => 'NOT NULL'}, 241: # ], 242: # 'PRIMARY KEY' => ['action_id',], 243: #}; 244: 245: my $machine_table_def = 246: { id => $tables{'machine'}, 247: permanent => 'no', 248: columns => [{ name => 'machine_id', 249: type => 'MEDIUMINT UNSIGNED', 250: restrictions => 'NOT NULL', 251: auto_inc => 'yes', }, 252: { name => 'machine', 253: type => 'VARCHAR(100)', 254: restrictions => 'NOT NULL'}, 255: ], 256: 'PRIMARY KEY' => ['machine_id',], 257: }; 258: 259: my $activity_table_def = 260: { id => $tables{'activity'}, 261: permanent => 'no', 262: columns => [ 263: { name => 'res_id', 264: type => 'MEDIUMINT UNSIGNED', 265: restrictions => 'NOT NULL',}, 266: { name => 'time', 267: type => 'DATETIME', 268: restrictions => 'NOT NULL',}, 269: { name => 'student_id', 270: type => 'MEDIUMINT UNSIGNED', 271: restrictions => 'NOT NULL',}, 272: { name => 'action', 273: type => 'VARCHAR(10)', 274: restrictions => 'NOT NULL',}, 275: { name => 'idx', # This is here in case a student 276: type => 'MEDIUMINT UNSIGNED', # has multiple submissions during 277: restrictions => 'NOT NULL', # one second. It happens, trust 278: auto_inc => 'yes', }, # me. 279: { name => 'machine_id', 280: type => 'MEDIUMINT UNSIGNED', 281: restrictions => 'NOT NULL',}, 282: { name => 'action_values', 283: type => 'MEDIUMTEXT', }, 284: ], 285: 'PRIMARY KEY' => ['time','student_id','res_id','idx'], 286: 'KEY' => [{columns => ['student_id']}, 287: {columns => ['time']},], 288: }; 289: 290: my @Activity_Table = ($activity_table_def); 291: my @ID_Tables = ($student_table_def,$res_table_def,$machine_table_def); 292: 293: ## 294: ## End of table definitions 295: ## 296: $logthis->('tables = '.join(',',keys(%tables))); 297: 298: $logthis->('Connectiong to mysql'); 299: &Apache::lonmysql::set_mysql_user_and_password('www', 300: $perlvar{'lonSqlAccess'}); 301: if (!&Apache::lonmysql::verify_sql_connection()) { 302: warn "Unable to connect to MySQL database."; 303: $logthis->("Unable to connect to MySQL database."); 304: &clean_up_and_exit(3); 305: } 306: $logthis->('SQL connection is up'); 307: 308: &update_process_name($course.'@'.$domain." loading existing data"); 309: my $missing_table = &check_for_missing_tables(values(%tables)); 310: if (-s $gz_sql_filename && ! -s $gz_xml_filename) { 311: my $backup_modification_time = (stat($gz_sql_filename))[9]; 312: $logthis->($gz_sql_filename.' was last modified '. 313: localtime($backup_modification_time). 314: '('.$backup_modification_time.')'); 315: if ($missing_table) { 316: # If the backup happened prior to the last table modification, 317: # we need to save the tables. 318: if (&latest_table_modification_time() > $backup_modification_time) { 319: # Save the current tables in case we need them another time. 320: $logthis->('Backing existing tables up'); 321: &backup_tables_as_xml($gz_xml_filename.'.save_'.time,\%tables); 322: } 323: $time_this->(); 324: &load_backup_sql_tables($gz_sql_filename); 325: &backup_tables_as_xml($gz_xml_filename,\%tables); 326: $time_this->('load backup tables'); 327: } 328: } elsif (-s $gz_xml_filename) { 329: my $backup_modification_time = (stat($gz_xml_filename))[9]; 330: $logthis->($gz_xml_filename.' was last modified '. 331: localtime($backup_modification_time). 332: '('.$backup_modification_time.')'); 333: if ($missing_table) { 334: my $table_modification_time = $backup_modification_time; 335: # If the backup happened prior to the last table modification, 336: # we need to save the tables. 337: if (&latest_table_modification_time() > $backup_modification_time) { 338: # Save the current tables in case we need them another time. 339: $logthis->('Backing existing tables up'); 340: &backup_tables_as_xml($gz_xml_filename.'.save_'.time,\%tables); 341: } 342: $time_this->(); 343: # We have to make our own tables for the xml format 344: &drop_tables(); 345: &create_tables(); 346: &load_backup_xml_tables($gz_xml_filename,\%tables); 347: $time_this->('load backup tables'); 348: } 349: } 350: 351: if (defined($xmlfile)) { 352: &clean_up_and_exit(0); 353: } 354: 355: ## 356: ## Ensure the tables we need exist 357: # create_tables does not complain if the tables already exist 358: $logthis->('creating tables'); 359: if (! &create_tables()) { 360: warn "Unable to create tables"; 361: $logthis->('Unable to create tables'); 362: &clean_up_and_exit(4); 363: } 364: 365: ## 366: ## Read the ids used for various tables 367: $logthis->('reading id tables'); 368: &read_id_tables(); 369: $logthis->('finished reading id tables'); 370: 371: ## 372: ## Set up the errors file 373: my $error_fh = IO::File->new(">>$error_filename"); 374: 375: ## 376: ## Parse the course log 377: $logthis->('processing course log'); 378: &update_process_name($course.'@'.$domain." processing new data"); 379: if (-s $newfilename) { 380: my $result = &process_courselog($newfilename,$error_fh,\%tables); 381: &update_process_name($course.'@'.$domain." backing up new data"); 382: if (! defined($result)) { 383: # Something went wrong along the way... 384: $logthis->('process_courselog returned undef'); 385: &clean_up_and_exit(5); 386: } elsif ($result > 0) { 387: $time_this->(); 388: $logthis->('process_courselog returned '.$result.'.'.$/. 389: 'Backing up tables'); 390: &backup_tables_as_xml($gz_xml_filename,\%tables); 391: $time_this->('write backup tables'); 392: } 393: if ($drop_when_done) { &drop_tables(); $logthis->('dropped tables'); } 394: } 395: close($error_fh); 396: 397: ## 398: ## Clean up the filesystem 399: &Apache::lonmysql::disconnect_from_db(); 400: unlink($newfilename) if (-e $newfilename && ! $nocleanup); 401: 402: ## 403: ## Print timing data 404: $logthis->('printing timing data'); 405: if ($time_run) { 406: my $elapsed_time = Time::HiRes::time - $initial_time; 407: print "Overall time: ".$elapsed_time.$/; 408: print &outputtimes(); 409: $logthis->("Overall time: ".$elapsed_time); 410: $logthis->(&outputtimes()); 411: } 412: 413: &clean_up_and_exit(0); 414: 415: ######################################################## 416: ######################################################## 417: 418: sub clean_up_and_exit { 419: my ($exit_code) = @_; 420: # Close files 421: close(LOCKFILE); 422: close(LOGFILE); 423: # Remove zero length files 424: foreach my $file ($lockfilename, $error_filename,$logfile) { 425: if (defined($file) && -z $file) { 426: unlink($file); 427: } 428: } 429: 430: exit $exit_code; 431: } 432: 433: ######################################################## 434: ######################################################## 435: sub table_names { 436: my ($course,$domain) = @_; 437: my $prefix = $course.'_'.$domain.'_'; 438: # 439: my %tables = 440: ( student =>&Apache::lonmysql::fix_table_name($prefix.'students'), 441: res =>&Apache::lonmysql::fix_table_name($prefix.'resource'), 442: machine =>&Apache::lonmysql::fix_table_name($prefix.'machine_table'), 443: activity=>&Apache::lonmysql::fix_table_name($prefix.'activity'), 444: ); 445: return %tables; 446: } 447: 448: ######################################################## 449: ######################################################## 450: ## 451: ## Process Course Log 452: ## 453: ######################################################## 454: ######################################################## 455: # 456: # Returns the number of lines in the activity.log file that were processed. 457: sub process_courselog { 458: my ($inputfile,$error_fh,$tables) = @_; 459: if (! open(IN,$inputfile)) { 460: warn "Unable to open '$inputfile' for reading"; 461: $logthis->("Unable to open '$inputfile' for reading"); 462: return undef; 463: } 464: my ($linecount,$insertcount); 465: my $dbh = &Apache::lonmysql::get_dbh(); 466: # 467: &store_entry(); 468: while (my $line=<IN>){ 469: # last if ($linecount > 1000); 470: # 471: # Bulk storage variables 472: $time_this->(); 473: chomp($line); 474: $linecount++; 475: # print $linecount++.$/; 476: my ($timestamp,$host,$log)=split(/\:/,$line,3); 477: # 478: # $log has the actual log entries; currently still escaped, and 479: # %26(timestamp)%3a(url)%3a(user)%3a(domain) 480: # then additionally 481: # %3aPOST%3a(name)%3d(value)%3a(name)%3d(value) 482: # or 483: # %3aCSTORE%3a(name)%3d(value)%26(name)%3d(value) 484: # or 485: # %3aPUTSTORE%3a(name)%3d(value)%26(name)%3d(value) 486: # 487: # get delimiter between timestamped entries to be &&& 488: $log=~s/\%26(\d{9,10})\%3a/\&\&\&$1\%3a/g; 489: $log = &unescape($log); 490: # now go over all log entries 491: if (! defined($host)) { $host = 'unknown'; } 492: my $prevchunk = 'none'; 493: foreach my $chunk (split(/\&\&\&/,$log)) { 494: if (length($chunk) > 20000) { 495: # avoid putting too much data into the database 496: # (usually an uploaded file or something similar) 497: if (! &savechunk(\$chunk,$timestamp,$host)) { 498: close(IN); 499: return undef; 500: } 501: next; 502: } 503: my $warningflag = ''; 504: my ($time,$res,$uname,$udom,$action,@values)= split(/:/,$chunk); 505: # 506: if (! defined($res) || $res =~ /^\s*$/) { 507: $res = '/adm/roles'; 508: $action = 'LOGIN'; 509: } 510: if ($res =~ m|^/prtspool/|) { 511: $res = '/prtspool/'; 512: } 513: if (! defined($action) || $action eq '') { 514: $action = 'VIEW'; 515: } 516: if ($action !~ /^(LOGIN|VIEW|POST|CSTORE|STORE|PUTSTORE)$/) { 517: $warningflag .= 'action'; 518: print $error_fh 'full log entry:'.$log.$/; 519: print $error_fh 'error on chunk (saving)'.$/; 520: if (! &savechunk(\$chunk,$timestamp,$host)) { 521: close(IN); 522: return undef; 523: } 524: $logthis->('(action) Unable to parse chunk'.$/. 525: 'got '. 526: 'time = '.$time.$/. 527: 'res = '.$res.$/. 528: 'uname= '.$uname.$/. 529: 'udom = '.$udom.$/. 530: 'action='.$action.$/. 531: '@values = '.join('&',@values)); 532: next; #skip it if we cannot understand what is happening. 533: } 534: # 535: my %data = (student => $uname.':'.$udom, 536: resource => $res, 537: machine => $host, 538: action => $action, 539: time => &Apache::lonmysql::sqltime($time)); 540: if ($action eq 'POST') { 541: $data{'action_values'} = 542: $dbh->quote(join('&',map { &escape($_); } @values)); 543: } else { 544: $data{'action_values'} = $dbh->quote(join('&',@values)); 545: } 546: my $error = &store_entry($dbh,$tables,\%data); 547: if ($error) { 548: $logthis->('error store_entry:'.$error." on %data"); 549: } 550: $prevchunk = $chunk; 551: } 552: } 553: my $result = &store_entry($dbh,$tables); 554: if (! defined($result)) { 555: my $error = &Apache::lonmysql::get_error(); 556: warn "Error occured during insert.".$error; 557: $logthis->('error = '.$error); 558: } 559: close IN; 560: return $linecount; 561: ## 562: ## 563: sub savechunk { 564: my ($chunkref,$timestamp,$host) = @_; 565: my $chunk = &escape(${$chunkref}); 566: if (! open(CHUNKFILE,">>$chunk_filename") || 567: ! print CHUNKFILE $timestamp.':'.$host.':'.$chunk.$/) { 568: # abort 569: close(CHUNKFILE); 570: return 0; 571: } 572: close(CHUNKFILE); 573: return 1; 574: } 575: } 576: 577: 578: ## 579: ## default value for $logthis and $time_this 580: sub nothing { 581: return; 582: } 583: 584: ## 585: ## Logging routine (look for $log) 586: ## 587: sub log_to_file { 588: my ($input)=@_; 589: print LOGFILE $input.$/; 590: } 591: 592: ## 593: ## Timing routines 594: ## 595: { 596: my %Timing; 597: my $starttime; 598: 599: sub time_action { 600: my ($key) = @_; 601: if (defined($key)) { 602: $Timing{$key}+=Time::HiRes::time-$starttime; 603: $Timing{'count_'.$key}++; 604: } 605: $starttime = Time::HiRes::time; 606: } 607: 608: sub outputtimes { 609: my $Str; 610: if ($time_run) { 611: $Str = "Timing Data:".$/; 612: while (my($k,$v) = each(%Timing)) { 613: next if ($k =~ /^count_/); 614: my $count = $Timing{'count_'.$k}; 615: $Str .= 616: ' '.sprintf("%25.25s",$k). 617: ' '.sprintf('% 8d',$count). 618: ' '.sprintf('%12.5f',$v).$/; 619: } 620: } 621: return $Str; 622: } 623: 624: } 625: 626: sub latest_table_modification_time { 627: my $latest_time; 628: foreach my $table (@Activity_Table,@ID_Tables) { 629: my %tabledata = &Apache::lonmysql::table_information($table->{'id'}); 630: next if (! scalar(keys(%tabledata))); # table does not exist 631: if (! defined($latest_time) || 632: $latest_time < $tabledata{'Update_time'}) { 633: $latest_time = $tabledata{'Update_time'}; 634: } 635: } 636: return $latest_time; 637: } 638: 639: sub check_for_missing_tables { 640: my @wanted_tables = @_; 641: # Check for missing tables 642: my @Current_Tables = &Apache::lonmysql::tables_in_db(); 643: my %Found; 644: foreach my $tablename (@Current_Tables) { 645: foreach my $table (@wanted_tables) { 646: if ($tablename eq $table) { 647: $Found{$tablename}++; 648: } 649: } 650: } 651: $logthis->('Found tables '.join(',',keys(%Found))); 652: my $missing_a_table = 0; 653: foreach my $table (@wanted_tables) { 654: if (! $Found{$table}) { 655: $logthis->('Missing table '.$table); 656: $missing_a_table = 1; 657: last; 658: } 659: } 660: return $missing_a_table; 661: } 662: 663: ## 664: ## Use mysqldump to store backups of the tables 665: ## 666: sub backup_tables_as_sql { 667: my ($gz_sql_filename) = @_; 668: my $command = qq{mysqldump --quote-names --opt loncapa }; 669: foreach my $table (@ID_Tables,@Activity_Table) { 670: my $tablename = $table->{'id'}; 671: $tablename =~ s/\`//g; 672: $command .= $tablename.' '; 673: } 674: $command .= '| gzip >'.$gz_sql_filename; 675: $logthis->($command); 676: system($command); 677: } 678: 679: ## 680: ## Load in mysqldumped files 681: ## 682: sub load_backup_sql_tables { 683: my ($gz_sql_filename) = @_; 684: if (-s $gz_sql_filename) { 685: $logthis->('loading data from gzipped sql file'); 686: my $command='gzip -dc '.$gz_sql_filename.' | mysql --database=loncapa'; 687: system($command); 688: $logthis->('finished loading gzipped data');; 689: } else { 690: return undef; 691: } 692: } 693: 694: ## 695: ## 696: ## 697: sub update_process_name { 698: my ($text) = @_; 699: $0 = 'parse_activity_log.pl: '.$text; 700: } 701: 702: sub get_filename { 703: my ($course,$domain) = @_; 704: my ($a,$b,$c,undef) = split('',$course,4); 705: return "$perlvar{'lonUsersDir'}/$domain/$a/$b/$c/$course/activity.log"; 706: } 707: 708: sub create_tables { 709: foreach my $table (@ID_Tables,@Activity_Table) { 710: my $table_id = &Apache::lonmysql::create_table($table); 711: if (! defined($table_id)) { 712: warn "Unable to create table ".$table->{'id'}.$/; 713: $logthis->('Unable to create table '.$table->{'id'}); 714: $logthis->(join($/,&Apache::lonmysql::build_table_creation_request($table))); 715: return 0; 716: } 717: } 718: return 1; 719: } 720: 721: sub drop_tables { 722: foreach my $table (@ID_Tables,@Activity_Table) { 723: my $table_id = $table->{'id'}; 724: &Apache::lonmysql::drop_table($table_id); 725: } 726: } 727: 728: ################################################################# 729: ################################################################# 730: ## 731: ## Database item id code 732: ## 733: ################################################################# 734: ################################################################# 735: { # Scoping for ID lookup code 736: my %IDs; 737: 738: sub read_id_tables { 739: foreach my $table (@ID_Tables) { 740: my @Data = &Apache::lonmysql::get_rows($table->{'id'}); 741: my $count = 0; 742: foreach my $row (@Data) { 743: $IDs{$table->{'id'}}->{$row->[1]} = $row->[0]; 744: } 745: } 746: return; 747: } 748: 749: sub get_id { 750: my ($table,$fieldname,$value) = @_; 751: if (exists($IDs{$table}->{$value}) && $IDs{$table}->{$value} =~ /^\d+$/) { 752: return $IDs{$table}->{$value}; 753: } else { 754: # insert into the table - if the item already exists, that is 755: # okay. 756: my $result = &Apache::lonmysql::store_row($table,[undef,$value]); 757: if (! defined($result)) { 758: warn("Got error on id insert for $value\n". 759: &Apache::lonmysql::get_error()); 760: } 761: # get the id 762: my $id = &Apache::lonmysql::get_dbh()->{'mysql_insertid'}; 763: if (defined($id)) { 764: $IDs{$table}->{$value}=$id; 765: } else { 766: $logthis->("Unable to retrieve id for $table $fieldname $value"); 767: return undef; 768: } 769: } 770: } 771: 772: } # End of ID scoping 773: 774: ############################################################### 775: ############################################################### 776: ## 777: ## Save as XML 778: ## 779: ############################################################### 780: ############################################################### 781: sub backup_tables_as_xml { 782: my ($filename,$tables) = @_; 783: open(XMLFILE,"|gzip - > $filename") || return ('error:unable to write '.$filename); 784: my $query = qq{ 785: SELECT B.resource, 786: A.time, 787: A.idx, 788: C.student, 789: A.action, 790: E.machine, 791: A.action_values 792: FROM $tables->{'activity'} AS A 793: LEFT JOIN $tables->{'res'} AS B ON B.res_id=A.res_id 794: LEFT JOIN $tables->{'student'} AS C ON C.student_id=A.student_id 795: LEFT JOIN $tables->{'machine'} AS E ON E.machine_id=A.machine_id 796: ORDER BY A.time DESC 797: }; 798: $query =~ s/\s+/ /g; 799: my $dbh = &Apache::lonmysql::get_dbh(); 800: my $sth = $dbh->prepare($query); 801: if (! $sth->execute()) { 802: $logthis->('<font color="blue">'. 803: 'WARNING: Could not retrieve from database:'. 804: $sth->errstr().'</font>'); 805: return undef; 806: } else { 807: my ($res,$sqltime,$idx,$student,$action,$machine,$action_values); 808: if ($sth->bind_columns(\$res,\$sqltime,\$idx,\$student,\$action, 809: \$machine,\$action_values)) { 810: 811: while ($sth->fetch) { 812: print XMLFILE '<row>'. 813: qq{<resource>$res</resource>}. 814: qq{<time>$sqltime</time>}. 815: qq{<idx>$idx</idx>}. 816: qq{<student>$student</student>}. 817: qq{<action>$action</action>}. 818: qq{<machine>$machine</machine>}. 819: qq{<action_values>$action_values</action_values>}. 820: '</row>'.$/; 821: } 822: } else { 823: warn "Unable to bind to columns.\n"; 824: return undef; 825: } 826: } 827: close XMLFILE; 828: return; 829: } 830: 831: ############################################################### 832: ############################################################### 833: ## 834: ## load as xml 835: ## 836: ############################################################### 837: ############################################################### 838: { 839: my @fields = ('resource','time', 840: 'student','action','idx','machine','action_values'); 841: my %ids = (); 842: sub load_backup_xml_tables { 843: my ($filename,$tables) = @_; 844: my $dbh = &Apache::lonmysql::get_dbh(); 845: my $xmlfh; 846: open($xmlfh,"cat $filename | gzip -d - |"); 847: if (! defined($xmlfh)) { 848: return ('error:unable to read '.$filename); 849: } 850: # 851: %ids = (resource=> {"\0count"=>1}, 852: student=> {"\0count"=>1}, 853: machine=> {"\0count"=>1}); 854: # 855: my %data; 856: while (my $inputline = <$xmlfh>) { 857: my ($resource,$time,undef,$student,$action,$machine,$action_values) = 858: ($inputline =~ m{<row> 859: <resource>(.*)</resource> 860: <time>(.*)</time> 861: <idx>(.*)</idx> 862: <student>(.*)</student> 863: <action>(.*)</action> 864: <machine>(.*)</machine> 865: <action_values>(.*)</action_values> 866: </row>$ 867: }x 868: ); 869: my $resource_id = &xml_get_id('resource',$resource); 870: my $student_id = &xml_get_id('student',$student); 871: my $machine_id = &xml_get_id('machine',$machine); 872: &xml_store_activity_row(map { defined($_)?$dbh->quote($_):'' 873: } ($resource_id, 874: $time, 875: $student_id, 876: $action, 877: 'NULL', 878: $machine_id, 879: $action_values)); 880: } 881: &xml_store_activity_row(); 882: close($xmlfh); 883: # Store id tables 884: while (my ($id_name,$id_data) = each(%ids)) { 885: if ($id_name eq 'resource') { $id_name = 'res'; } 886: delete($id_data->{"\0count"}); 887: &xml_store_id_table($id_name,$id_data); 888: } 889: return; 890: } 891: 892: sub xml_get_id { 893: my ($table,$element) = @_; 894: if (! exists($ids{$table}->{$element})) { 895: $ids{$table}->{$element} = $ids{$table}->{"\0count"}++; 896: } 897: return $ids{$table}->{$element}; 898: } 899: 900: { 901: my @data_rows; 902: sub xml_store_activity_row { 903: my @data = @_; 904: if (scalar(@data)) { 905: push(@data_rows,[@data]); 906: } 907: if (! scalar(@data) || scalar(@data_rows) > 500) { 908: if (! &Apache::lonmysql::bulk_store_rows($tables{'activity'}, 909: scalar(@{$data_rows[0]}), 910: \@data_rows)) { 911: $logthis->("Error:".&Apache::lonmysql::get_error()); 912: warn("Error:".&Apache::lonmysql::get_error()); 913: } else { 914: undef(@data_rows); 915: } 916: } 917: return; 918: } 919: 920: } 921: 922: sub xml_store_id_table { 923: my ($table,$tabledata) =@_; 924: my $dbh = &Apache::lonmysql::get_dbh(); 925: if (! &Apache::lonmysql::bulk_store_rows 926: ($tables{$table},2, 927: [map{[$tabledata->{$_},$dbh->quote($_)]} keys(%$tabledata)])) { 928: $logthis->("Error:".&Apache::lonmysql::get_error()); 929: warn "Error:".&Apache::lonmysql::get_error().$/; 930: } 931: } 932: 933: } # End of load xml scoping 934: 935: ####################################################################### 936: ####################################################################### 937: ## 938: ## store_entry - accumulate data to be inserted into the database 939: ## 940: ## Pass no values in to clear accumulator 941: ## Pass ($dbh,\%tables) to initiate storage of values 942: ## Pass ($dbh,\%tables,\%data) to use normally 943: ## 944: ####################################################################### 945: ####################################################################### 946: { 947: my @rows; 948: 949: sub store_entry { 950: my $max_row_count = 100; 951: if (! @_) { 952: undef(@rows); 953: return ''; 954: } 955: my ($dbh,$tables,$data) = @_; 956: return if (! defined($tables)); 957: if (defined($data)) { 958: my $error; 959: foreach my $field ('student','resource','action','time') { 960: if (! defined($data->{$field}) || $data->{$field} eq ':' || 961: $data->{$field}=~ /^\s*$/) { 962: $error.=$field.','; 963: } 964: } 965: if ($error) { $error=~s/,$//; return $error; } 966: # 967: my $student_id = &get_id($tables->{'student'},'student', 968: $data->{'student'}); 969: my $res_id = &get_id($tables->{'res'}, 970: 'resource',$data->{'resource'}); 971: my $machine_id = &get_id($tables->{'machine'}, 972: 'machine',$data->{'machine'}); 973: my $idx = $data->{'idx'}; if (! $idx) { $idx = "''"; } 974: # 975: push(@rows,[$res_id, 976: qq{'$data->{'time'}'}, 977: $student_id, 978: qq{'$data->{'action'}'}, 979: $idx, 980: $machine_id, 981: $data->{'action_values'}]); 982: } 983: if (defined($tables) && 984: ( (! defined($data) && scalar(@rows)) || scalar(@rows)>$max_row_count) 985: ){ 986: # Store the rows 987: my $result = 988: &Apache::lonmysql::bulk_store_rows($tables->{'activity'}, 989: undef, 990: \@rows); 991: if (! defined($result)) { 992: my $error = &Apache::lonmysql::get_error(); 993: warn "Error occured during insert.".$error; 994: return $error; 995: } 996: undef(@rows); 997: return $result if (! defined($data)); 998: } 999: return ''; 1000: } 1001: 1002: } # end of scope for &store_entry 1003: 1004: ############################################################### 1005: ############################################################### 1006: ## 1007: ## The usual suspects 1008: ## 1009: ############################################################### 1010: ############################################################### 1011: sub escape { 1012: my $str=shift; 1013: $str =~ s/(\W)/"%".unpack('H2',$1)/eg; 1014: return $str; 1015: } 1016: 1017: sub unescape { 1018: my $str=shift; 1019: $str =~ s/%([a-fA-F0-9][a-fA-F0-9])/pack("C",hex($1))/eg; 1020: return $str; 1021: }