Commit 5febc3e0 authored by sikeda's avatar sikeda
Browse files

[-dev] Normalize log messages (except in wwsympa.fcgi).

- Use sprintf format instead of string interpolation: Latter is potentially insecure.
- Function/method names in messages are removed because they are automatically prepended by Log::do?log().
- Otheer cosmetic issues.


git-svn-id: https://subversion.renater.fr/sympa/branches/sympa-6.2-branch@10849 05aa8bb8-cd2b-0410-b1d7-8918dfa770ce
parent 7df015ed
...@@ -52,8 +52,11 @@ if ($main::options{'log_level'}) { ...@@ -52,8 +52,11 @@ if ($main::options{'log_level'}) {
); );
} else { } else {
Log::set_log_level($Conf::Conf{'log_level'}); Log::set_log_level($Conf::Conf{'log_level'});
Log::do_log('info', Log::do_log(
"Logs seems OK, default log level $Conf::Conf{'log_level'}"); 'info',
'Logs seems OK, default log level %s',
$Conf::Conf{'log_level'}
);
} }
printf "Ok, now check logs \n"; printf "Ok, now check logs \n";
......
...@@ -46,7 +46,7 @@ my $serial_number = 0; # incremented on each archived mail ...@@ -46,7 +46,7 @@ my $serial_number = 0; # incremented on each archived mail
sub store_last { sub store_last {
my ($list, $msg) = @_; my ($list, $msg) = @_;
Log::do_log('debug2', 'archive::store ()'); Log::do_log('debug2', '');
my ($filename, $newfile); my ($filename, $newfile);
...@@ -73,20 +73,19 @@ sub store_last { ...@@ -73,20 +73,19 @@ sub store_last {
sub list { sub list {
my $name = shift; my $name = shift;
Log::do_log('debug', "archive::list($name)"); Log::do_log('debug', '(%s)', $name);
my ($filename, $newfile); my ($filename, $newfile);
my (@l, $i); my (@l, $i);
unless (-d "$name") { unless (-d "$name") {
Log::do_log('warning', Log::do_log('warning', '(%s) Failed, no directory %s', $name, $name);
"archive::list($name) failed, no directory $name");
# @l = ($msg::no_archives_available); # @l = ($msg::no_archives_available);
return @l; return @l;
} }
unless (opendir(DIR, "$name")) { unless (opendir(DIR, "$name")) {
Log::do_log('warning', Log::do_log('warning', '(%s) Failed, cannot open directory %s',
"archive::list($name) failed, cannot open directory $name"); $name, $name);
# @l = ($msg::no_archives_available); # @l = ($msg::no_archives_available);
return @l; return @l;
} }
...@@ -104,7 +103,7 @@ sub scan_dir_archive { ...@@ -104,7 +103,7 @@ sub scan_dir_archive {
my ($dir, $month) = @_; my ($dir, $month) = @_;
Log::do_log('info', "archive::scan_dir_archive($dir, $month)"); Log::do_log('info', '(%s, %s)', $dir, $month);
unless (opendir(DIR, "$dir/$month/arctxt")) { unless (opendir(DIR, "$dir/$month/arctxt")) {
Log::do_log('info', Log::do_log('info',
...@@ -131,7 +130,7 @@ sub scan_dir_archive { ...@@ -131,7 +130,7 @@ sub scan_dir_archive {
return undef; return undef;
} }
Log::do_log('debug', "MAIL object : $mail"); Log::do_log('debug', 'MAIL object: %s', $mail);
$i++; $i++;
my $msg = {}; my $msg = {};
...@@ -143,11 +142,8 @@ sub scan_dir_archive { ...@@ -143,11 +142,8 @@ sub scan_dir_archive {
$msg->{'full_msg'} = $mail->{'msg'}->as_string; $msg->{'full_msg'} = $mail->{'msg'}->as_string;
Log::do_log( Log::do_log('debug', 'Adding message %s in archive to send',
'debug', $msg->{'subject'});
'Archive::scan_dir_archive adding message %s in archive to send',
$msg->{'subject'}
);
push @{$all_msg}, $msg; push @{$all_msg}, $msg;
} }
...@@ -172,14 +168,14 @@ sub search_msgid { ...@@ -172,14 +168,14 @@ sub search_msgid {
my ($dir, $msgid) = @_; my ($dir, $msgid) = @_;
Log::do_log('info', "archive::search_msgid($dir, $msgid)"); Log::do_log('info', '(%s, %s)', $dir, $msgid);
if ($msgid =~ /NO-ID-FOUND\.mhonarc\.org/) { if ($msgid =~ /NO-ID-FOUND\.mhonarc\.org/) {
Log::do_log('err', 'remove_arc: no message id found'); Log::do_log('err', 'No message id found');
return undef; return undef;
} }
unless ($dir =~ /\d\d\d\d\-\d\d\/arctxt/) { unless ($dir =~ /\d\d\d\d\-\d\d\/arctxt/) {
Log::do_log('info', "archive::search_msgid : dir $dir look unproper"); Log::do_log('info', 'Dir %s look unproper', $dir);
return undef; return undef;
} }
unless (opendir(ARC, "$dir")) { unless (opendir(ARC, "$dir")) {
...@@ -222,7 +218,7 @@ sub last_path { ...@@ -222,7 +218,7 @@ sub last_path {
my $list = shift; my $list = shift;
Log::do_log('debug', 'Archived::last_path(%s)', $list->{'name'}); Log::do_log('debug', '(%s)', $list->{'name'});
return undef unless ($list->is_archived()); return undef unless ($list->is_archived());
my $file = $list->{'dir'} . '/archives/last_message'; my $file = $list->{'dir'} . '/archives/last_message';
...@@ -244,7 +240,7 @@ sub load_html_message { ...@@ -244,7 +240,7 @@ sub load_html_message {
unless (open ARC, $parameters{'file_path'}) { unless (open ARC, $parameters{'file_path'}) {
Log::do_log( Log::do_log(
'err', 'err',
"Failed to load message '%s' : $!", 'Failed to load message "%s": %m',
$parameters{'file_path'} $parameters{'file_path'}
); );
return undef; return undef;
...@@ -289,7 +285,7 @@ sub clean_archive_directory { ...@@ -289,7 +285,7 @@ sub clean_archive_directory {
) { ) {
Log::do_log( Log::do_log(
'err', 'err',
"Unable to create a temporary directory where to store files for HTML escaping (%s). Cancelling.", 'Unable to create a temporary directory where to store files for HTML escaping (%s). Cancelling',
$number_of_copies $number_of_copies
); );
return undef; return undef;
...@@ -304,7 +300,7 @@ sub clean_archive_directory { ...@@ -304,7 +300,7 @@ sub clean_archive_directory {
closedir DIR; closedir DIR;
if ($files_left_uncleaned) { if ($files_left_uncleaned) {
Log::do_log('err', Log::do_log('err',
"HTML cleaning failed for %s files in the directory %s.", 'HTML cleaning failed for %s files in the directory %s',
$files_left_uncleaned, $answer->{'dir_to_rebuild'}); $files_left_uncleaned, $answer->{'dir_to_rebuild'});
} }
$answer->{'dir_to_rebuild'} = $answer->{'cleaned_dir'}; $answer->{'dir_to_rebuild'} = $answer->{'cleaned_dir'};
...@@ -347,7 +343,7 @@ sub clean_archived_message { ...@@ -347,7 +343,7 @@ sub clean_archived_message {
return undef; return undef;
} }
} else { } else {
Log::do_log('err', 'HTML cleaning in file %s failed.', $output); Log::do_log('err', 'HTML cleaning in file %s failed', $output);
return undef; return undef;
} }
} }
......
...@@ -42,7 +42,7 @@ use Sympa::User; ...@@ -42,7 +42,7 @@ use Sympa::User;
## by sha1 or ....) ## by sha1 or ....)
sub password_fingerprint { sub password_fingerprint {
Log::do_log('debug', 'Auth::password_fingerprint'); Log::do_log('debug', '');
my $pwd = shift; my $pwd = shift;
if (Conf::get_robot_conf('*', 'password_case') eq 'insensitive') { if (Conf::get_robot_conf('*', 'password_case') eq 'insensitive') {
...@@ -57,7 +57,7 @@ sub check_auth { ...@@ -57,7 +57,7 @@ sub check_auth {
my $robot = shift; my $robot = shift;
my $auth = shift; ## User email or UID my $auth = shift; ## User email or UID
my $pwd = shift; ## Password my $pwd = shift; ## Password
Log::do_log('debug', 'Auth::check_auth(%s)', $auth); Log::do_log('debug', '(%s)', $auth);
my ($canonic, $user); my ($canonic, $user);
...@@ -124,7 +124,7 @@ sub may_use_sympa_native_auth { ...@@ -124,7 +124,7 @@ sub may_use_sympa_native_auth {
sub authentication { sub authentication {
my ($robot, $email, $pwd) = @_; my ($robot, $email, $pwd) = @_;
my ($user, $canonic); my ($user, $canonic);
Log::do_log('debug', 'Auth::authentication(%s)', $email); Log::do_log('debug', '(%s)', $email);
unless ($user = Sympa::User::get_global_user($email)) { unless ($user = Sympa::User::get_global_user($email)) {
$user = {'email' => $email}; $user = {'email' => $email};
...@@ -141,7 +141,7 @@ sub authentication { ...@@ -141,7 +141,7 @@ sub authentication {
report::reject_report_web('user', 'too_many_wrong_login', {}) report::reject_report_web('user', 'too_many_wrong_login', {})
unless ($ENV{'SYMPA_SOAP'}); unless ($ENV{'SYMPA_SOAP'});
Log::do_log('err', Log::do_log('err',
'login is blocked : too many wrong password submission for %s', 'Login is blocked: too many wrong password submission for %s',
$email); $email);
return undef; return undef;
} }
...@@ -192,8 +192,7 @@ sub authentication { ...@@ -192,8 +192,7 @@ sub authentication {
report::reject_report_web('user', 'incorrect_passwd', {}) report::reject_report_web('user', 'incorrect_passwd', {})
unless ($ENV{'SYMPA_SOAP'}); unless ($ENV{'SYMPA_SOAP'});
Log::do_log('err', 'authentication: incorrect password for user %s', Log::do_log('err', 'Incorrect password for user %s', $email);
$email);
my $param; #FIXME FIXME: not used. my $param; #FIXME FIXME: not used.
$param->{'init_email'} = $email; $param->{'init_email'} = $email;
...@@ -204,8 +203,7 @@ sub authentication { ...@@ -204,8 +203,7 @@ sub authentication {
sub ldap_authentication { sub ldap_authentication {
my ($robot, $ldap, $auth, $pwd, $whichfilter) = @_; my ($robot, $ldap, $auth, $pwd, $whichfilter) = @_;
my ($mesg, $host, $ldap_passwd, $ldap_anonymous); my ($mesg, $host, $ldap_passwd, $ldap_anonymous);
Log::do_log('debug2', 'Auth::ldap_authentication(%s,%s,%s)', Log::do_log('debug2', '(%s, %s, %s)', $auth, '****', $whichfilter);
$auth, '****', $whichfilter);
Log::do_log('debug3', 'Password used: %s', $pwd); Log::do_log('debug3', 'Password used: %s', $pwd);
unless (tools::search_fullpath($robot, 'auth.conf')) { unless (tools::search_fullpath($robot, 'auth.conf')) {
...@@ -238,7 +236,7 @@ sub ldap_authentication { ...@@ -238,7 +236,7 @@ sub ldap_authentication {
my $ds = LDAPSource->new($param); my $ds = LDAPSource->new($param);
unless (defined $ds && ($ldap_anonymous = $ds->connect())) { unless (defined $ds && ($ldap_anonymous = $ds->connect())) {
Log::do_log('err', "Unable to connect to the LDAP server '%s'", Log::do_log('err', 'Unable to connect to the LDAP server "%s"',
$ldap->{'host'}); $ldap->{'host'});
return undef; return undef;
} }
...@@ -273,7 +271,7 @@ sub ldap_authentication { ...@@ -273,7 +271,7 @@ sub ldap_authentication {
$ds = LDAPSource->new($param); $ds = LDAPSource->new($param);
unless (defined $ds && ($ldap_passwd = $ds->connect())) { unless (defined $ds && ($ldap_passwd = $ds->connect())) {
Log::do_log('err', "Unable to connect to the LDAP server '%s'", Log::do_log('err', 'Unable to connect to the LDAP server "%s"',
$param->{'host'}); $param->{'host'});
return undef; return undef;
} }
...@@ -323,8 +321,8 @@ sub ldap_authentication { ...@@ -323,8 +321,8 @@ sub ldap_authentication {
$param->{'alt_emails'}{$alt} = $previous->{$alt}; $param->{'alt_emails'}{$alt} = $previous->{$alt};
} }
$ds->disconnect() or Log::do_log('notice', "unable to unbind"); $ds->disconnect() or Log::do_log('notice', 'Unable to unbind');
Log::do_log('debug3', "canonic: $canonic_email[0]"); Log::do_log('debug3', 'Canonic: %s', $canonic_email[0]);
## If the identifier provided was a valid email, return the provided ## If the identifier provided was a valid email, return the provided
## email. ## email.
## Otherwise, return the canonical email guessed after the login. ## Otherwise, return the canonical email guessed after the login.
...@@ -343,8 +341,7 @@ sub get_email_by_net_id { ...@@ -343,8 +341,7 @@ sub get_email_by_net_id {
my $auth_id = shift; my $auth_id = shift;
my $attributes = shift; my $attributes = shift;
Log::do_log('debug', Log::do_log('debug', '(%s, %s)', $auth_id, $attributes->{'uid'});
"Auth::get_email_by_net_id($auth_id,$attributes->{'uid'})");
if (defined $Conf::Conf{'auth_services'}{$robot}[$auth_id] if (defined $Conf::Conf{'auth_services'}{$robot}[$auth_id]
{'internal_email_by_netid'}) { {'internal_email_by_netid'}) {
...@@ -367,7 +364,7 @@ sub get_email_by_net_id { ...@@ -367,7 +364,7 @@ sub get_email_by_net_id {
my $ldap_anonymous; my $ldap_anonymous;
unless (defined $ds && ($ldap_anonymous = $ds->connect())) { unless (defined $ds && ($ldap_anonymous = $ds->connect())) {
Log::do_log('err', "Unable to connect to the LDAP server '%s'", Log::do_log('err', 'Unable to connect to the LDAP server "%s"',
$ldap->{'ldap_host'}); $ldap->{'ldap_host'});
return undef; return undef;
} }
...@@ -408,8 +405,7 @@ sub get_email_by_net_id { ...@@ -408,8 +405,7 @@ sub get_email_by_net_id {
sub remote_app_check_password { sub remote_app_check_password {
my ($trusted_application_name, $password, $robot) = @_; my ($trusted_application_name, $password, $robot) = @_;
Log::do_log('debug', 'Auth::remote_app_check_password (%s,%s)', Log::do_log('debug', '(%s, %s)', $trusted_application_name, $robot);
$trusted_application_name, $robot);
my $md5 = tools::md5_fingerprint($password); my $md5 = tools::md5_fingerprint($password);
...@@ -424,7 +420,7 @@ sub remote_app_check_password { ...@@ -424,7 +420,7 @@ sub remote_app_check_password {
if (lc($application->{'name'}) eq lc($trusted_application_name)) { if (lc($application->{'name'}) eq lc($trusted_application_name)) {
if ($md5 eq $application->{'md5password'}) { if ($md5 eq $application->{'md5password'}) {
# Log::do_log('debug', 'Auth::remote_app_check_password : authentication succeed for %s',$application->{'name'}); # Log::do_log('debug', 'Authentication succeed for %s',$application->{'name'});
my %proxy_for_vars; my %proxy_for_vars;
foreach my $varname (@{$application->{'proxy_for_variables'}}) foreach my $varname (@{$application->{'proxy_for_variables'}})
{ {
...@@ -432,16 +428,14 @@ sub remote_app_check_password { ...@@ -432,16 +428,14 @@ sub remote_app_check_password {
} }
return (\%proxy_for_vars); return (\%proxy_for_vars);
} else { } else {
Log::do_log('info', Log::do_log('info', 'Bad password from %s',
'Auth::remote_app_check_password: bad password from %s',
$trusted_application_name); $trusted_application_name);
return undef; return undef;
} }
} }
} }
# no matching application found # no matching application found
Log::do_log('info', Log::do_log('info', '-check_password: unknown application name %s',
'Auth::remote_app-check_password: unknown application name %s',
$trusted_application_name); $trusted_application_name);
return undef; return undef;
} }
...@@ -458,8 +452,7 @@ sub create_one_time_ticket { ...@@ -458,8 +452,7 @@ sub create_one_time_ticket {
shift; ## Value may be 'mail' if the IP address is not known shift; ## Value may be 'mail' if the IP address is not known
my $ticket = SympaSession::get_random(); my $ticket = SympaSession::get_random();
Log::do_log('info', Log::do_log('info', '(%s, %s, %s, %s) Value = %s',
'Auth::create_one_time_ticket(%s,%s,%s,%s) value = %s',
$email, $robot, $data_string, $remote_addr, $ticket); $email, $robot, $data_string, $remote_addr, $ticket);
my $date = time; my $date = time;
...@@ -513,9 +506,7 @@ sub get_one_time_ticket { ...@@ -513,9 +506,7 @@ sub get_one_time_ticket {
my $ticket = $sth->fetchrow_hashref('NAME_lc'); my $ticket = $sth->fetchrow_hashref('NAME_lc');
unless ($ticket) { unless ($ticket) {
Log::do_log('info', Log::do_log('info', 'Unable to find one time ticket %s', $ticket);
'Auth::get_one_time_ticket: Unable to find one time ticket %s',
$ticket);
return {'result' => 'not_found'}; return {'result' => 'not_found'};
} }
...@@ -525,21 +516,11 @@ sub get_one_time_ticket { ...@@ -525,21 +516,11 @@ sub get_one_time_ticket {
if ($ticket->{'status'} ne 'open') { if ($ticket->{'status'} ne 'open') {
$result = 'closed'; $result = 'closed';
Log::do_log( Log::do_log('info', 'Ticket %s from %s has been used before (%s)',
'info', $ticket_number, $ticket->{'email'}, $printable_date);
'Auth::get_one_time_ticket: ticket %s from %s has been used before (%s)',
$ticket_number,
$ticket->{'email'},
$printable_date
);
} elsif (time - $ticket->{'date'} > 48 * 60 * 60) { } elsif (time - $ticket->{'date'} > 48 * 60 * 60) {
Log::do_log( Log::do_log('info', 'Ticket %s from %s refused because expired (%s)',
'info', $ticket_number, $ticket->{'email'}, $printable_date);
'Auth::get_one_time_ticket: ticket %s from %s refused because expired (%s)',
$ticket_number,
$ticket->{'email'},
$printable_date
);
$result = 'expired'; $result = 'expired';
} else { } else {
$result = 'success'; $result = 'success';
...@@ -555,8 +536,7 @@ sub get_one_time_ticket { ...@@ -555,8 +536,7 @@ sub get_one_time_ticket {
$ticket_number, $addr); $ticket_number, $addr);
} }
Log::do_log('info', 'Auth::get_one_time_ticket(%s) : result : %s', Log::do_log('info', '(%s) Result: %s', $ticket_number, $result);
$ticket_number, $result);
return { return {
'result' => $result, 'result' => $result,
'date' => $ticket->{'date'}, 'date' => $ticket->{'date'},
......
...@@ -63,7 +63,7 @@ my $message_fingerprint; ...@@ -63,7 +63,7 @@ my $message_fingerprint;
# Next lock the packetb to prevent multiple proccessing of a single packet # Next lock the packetb to prevent multiple proccessing of a single packet
sub next { sub next {
Log::do_log('debug', 'Bulk::next'); Log::do_log('debug', '');
# lock next packet # lock next packet
my $lock = tools::get_lockname(); my $lock = tools::get_lockname();
...@@ -167,7 +167,7 @@ sub remove { ...@@ -167,7 +167,7 @@ sub remove {
my $messagekey = shift; my $messagekey = shift;
my $packetid = shift; my $packetid = shift;
Log::do_log('debug', "Bulk::remove(%s,%s)", $messagekey, $packetid); Log::do_log('debug', '(%s, %s)', $messagekey, $packetid);
unless ( unless (
$sth = SDM::do_query( $sth = SDM::do_query(
...@@ -185,7 +185,7 @@ sub remove { ...@@ -185,7 +185,7 @@ sub remove {
sub messageasstring { sub messageasstring {
my $messagekey = shift; my $messagekey = shift;
Log::do_log('debug', 'Bulk::messageasstring(%s)', $messagekey); Log::do_log('debug', '(%s)', $messagekey);
unless ( unless (
$sth = SDM::do_query( $sth = SDM::do_query(
...@@ -204,7 +204,8 @@ sub messageasstring { ...@@ -204,7 +204,8 @@ sub messageasstring {
my $messageasstring = $sth->fetchrow_hashref('NAME_lc'); my $messageasstring = $sth->fetchrow_hashref('NAME_lc');
unless ($messageasstring) { unless ($messageasstring) {
Log::do_log('err', "could not fetch message $messagekey from spool"); Log::do_log('err', 'Could not fetch message %s from spool',
$messagekey);
return undef; return undef;
} }
my $msg = MIME::Base64::decode($messageasstring->{'message'}); my $msg = MIME::Base64::decode($messageasstring->{'message'});
...@@ -221,7 +222,7 @@ sub messageasstring { ...@@ -221,7 +222,7 @@ sub messageasstring {
# #
sub message_from_spool { sub message_from_spool {
my $messagekey = shift; my $messagekey = shift;
Log::do_log('debug', '(messagekey : %s)', $messagekey); Log::do_log('debug', '(messagekey: %s)', $messagekey);
unless ( unless (
$sth = SDM::do_query( $sth = SDM::do_query(
...@@ -271,7 +272,7 @@ sub merge_msg { ...@@ -271,7 +272,7 @@ sub merge_msg {
my $data = shift; my $data = shift;
unless (ref $entity eq 'MIME::Entity') { unless (ref $entity eq 'MIME::Entity') {
Log::do_log('err', 'false entity'); Log::do_log('err', 'False entity');
return undef; return undef;
} }
...@@ -377,7 +378,7 @@ sub _merge_msg { ...@@ -377,7 +378,7 @@ sub _merge_msg {
'message_output' => \$message_output, 'message_output' => \$message_output,
) )
) { ) {
Log::do_log('err', 'error merging message'); Log::do_log('err', 'Error merging message');
return undef; return undef;
} }
$utf8_body = $message_output; $utf8_body = $message_output;
...@@ -478,7 +479,7 @@ sub merge_data { ...@@ -478,7 +479,7 @@ sub merge_data {
# Parse the TT2 in the message : replace the tags and the parameters by # Parse the TT2 in the message : replace the tags and the parameters by
# the corresponding values # the corresponding values
unless (tt2::parse_tt2($data, \$body, $message_output, '', $options)) { unless (tt2::parse_tt2($data, \$body, $message_output, '', $options)) {
Log::do_log('err', 'Unable to parse body : "%s"', \$body); Log::do_log('err', 'Unable to parse body: "%s"', \$body);
return undef; return undef;
} }
...@@ -510,7 +511,7 @@ sub store { ...@@ -510,7 +511,7 @@ sub store {
Log::do_log( Log::do_log(
'debug', 'debug',
'Bulk::store(<msg>,<rcpts>,from = %s,robot = %s,listname= %s,priority_message = %s, delivery_date= %s,verp = %s, tracking = %s, merge = %s, dkim: d= %s i=%s, last: %s)', '(<msg>, <rcpts>, from = %s, robot = %s, listname= %s, priority_message = %s, delivery_date= %s, verp = %s, tracking = %s, merge = %s, dkim: d= %s i=%s, last: %s)',
$from, $from,
$robot, $robot,
$listname, $listname,
...@@ -744,7 +745,7 @@ sub store { ...@@ -744,7 +745,7 @@ sub store {
## remove file that are not referenced by any packet ## remove file that are not referenced by any packet
sub purge_bulkspool { sub purge_bulkspool {
Log::do_log('debug', 'purge_bulkspool'); Log::do_log('debug', '');
unless ( unless (
$sth = SDM::do_query( $sth = SDM::do_query(
...@@ -812,7 +813,7 @@ sub store_test { ...@@ -812,7 +813,7 @@ sub store_test {
Log::do_log