Commit df95edb Issue 49835 - lib389: fix logging

12 files Authored by stlaz 6 days ago , Committed by Simon Pichugin 6 days ago ,
Issue 49835 - lib389: fix logging

The python standard logging module allows to postpone the string
interpolation in logs till the time the interpolation is actually
needed (note that you may be running in a certain logging level
that won't need to display/write all strings). This behavior is
there to comply with the logging requirement so that logs don't
affect the performance if no logging happens.

The above behavior only works when strings are passed as arguments
to the logging methods. If the interpolation is invoked at place
either by using the `%` notation or by using the `str.format()`
method, python logging can't perform its performance heuristics
since the strings get interpolated before they are handed to the
logging methods.

This commit fixes the improper behavior observed in the lib389
library, plus adds some fixes to improper invokes of the logging
methods - multiple arguments if formatting string does not contain
formatting variables -  which would cause internal logging errors
that don't cause the scripts failures, which is why they probably
weren't reported yet.

https://pagure.io/389-ds-base/issue/49835

Reviewed by: mreynolds, spichugi

Signed-off-by: Simon Pichugin <simon.pichugin@gmail.com>

    
  1 @@ -434,7 +434,7 @@
  2           self.binddn = binddn
  3           self.bindpw = password
  4           self.state = DIRSRV_STATE_ALLOCATED
  5 -         self.log.info("Allocate local instance %s with %s" % (self.__class__, self.ldapuri))
  6 +         self.log.info("Allocate local instance %s with %s", self.__class__, self.ldapuri)
  7   
  8       def remote_simple_allocate(self, ldapuri, binddn='cn=Directory Manager', password=None):
  9           """Allocate an instance, and perform a simple bind. This instance is remote, so
 10 @@ -465,7 +465,7 @@
 11           self.binddn = binddn
 12           self.bindpw = password
 13           self.state = DIRSRV_STATE_ALLOCATED
 14 -         self.log.info("Allocate %s with %s" % (self.__class__, self.ldapuri))
 15 +         self.log.info("Allocate %s with %s", self.__class__, self.ldapuri)
 16   
 17       # Should there be an extra boolean to this function to determine to use
 18       #  ldapi or not? Or does the settings presence indicate intent?
 19 @@ -515,7 +515,7 @@
 20           self.ldapi_enabled = args.get(SER_LDAPI_ENABLED, 'off')
 21           self.ldapi_socket = args.get(SER_LDAPI_SOCKET, None)
 22           self.ldapuri = args.get(SER_LDAP_URL, None)
 23 -         self.log.debug("Allocate %s with %s" % (self.__class__, self.ldapuri))
 24 +         self.log.debug("Allocate %s with %s", self.__class__, self.ldapuri)
 25           # Still needed in setup, even if ldapuri over writes.
 26           self.host = args.get(SER_HOST, socket.gethostname())
 27           self.port = args.get(SER_PORT, DEFAULT_PORT)
 28 @@ -528,7 +528,7 @@
 29               self.ldapi_autobind = args.get(SER_LDAPI_AUTOBIND, 'off')
 30               self.isLocal = True
 31               if self.verbose:
 32 -                 self.log.info("Allocate %s with %s" % (self.__class__, self.ldapi_socket))
 33 +                 self.log.info("Allocate %s with %s", self.__class__, self.ldapi_socket)
 34           # Settings from args of server attributes
 35           self.strict_hostname = args.get(SER_STRICT_HOSTNAME_CHECKING, False)
 36           if self.strict_hostname is True:
 37 @@ -539,7 +539,7 @@
 38                   DirSrvTools.searchHostsFile(self.host, None)
 39               self.isLocal = isLocalHost(self.host)
 40   
 41 -         self.log.debug("Allocate %s with %s:%s" % (self.__class__, self.host, (self.sslport or self.port)))
 42 +         self.log.debug("Allocate %s with %s:%s", self.__class__, self.host, (self.sslport or self.port))
 43   
 44           self.binddn = args.get(SER_ROOT_DN, DN_DM)
 45           self.bindpw = args.get(SER_ROOT_PW, PW_DM)
 46 @@ -565,10 +565,10 @@
 47   
 48           self.state = DIRSRV_STATE_ALLOCATED
 49           if self.verbose:
 50 -             self.log.info("Allocate %s with %s:%s" % (self.__class__,
 51 -                                                       self.host,
 52 -                                                       (self.sslport or
 53 -                                                        self.port)))
 54 +             self.log.info("Allocate %s with %s:%s",
 55 +                           self.__class__,
 56 +                           self.host,
 57 +                           (self.sslport or self.port))
 58   
 59       def clone(self, args_instance={}):
 60           """
 61 @@ -774,9 +774,9 @@
 62           if not os.path.isdir(sysconfig_head):
 63               privconfig_head = None
 64           if self.verbose:
 65 -             self.log.info("dir (sys) : %s" % sysconfig_head)
 66 +             self.log.info("dir (sys) : %s", sysconfig_head)
 67           if privconfig_head and self.verbose:
 68 -             self.log.info("dir (priv): %s" % privconfig_head)
 69 +             self.log.info("dir (priv): %s", privconfig_head)
 70   
 71           # list of the found instances
 72           instances = []
 73 @@ -794,9 +794,9 @@
 74                                                  DEFAULT_ENV_HEAD)
 75                   found = search_dir(instances, pattern, serverid)
 76                   if self.verbose and len(instances) > 0:
 77 -                     self.log.info("List from %s" % privconfig_head)
 78 +                     self.log.info("List from %s", privconfig_head)
 79                       for instance in instances:
 80 -                         self.log.info("list instance %r\n" % instance)
 81 +                         self.log.info("list instance %r\n", instance)
 82                   if found:
 83                       assert len(instances) == 1
 84                   else:
 85 @@ -810,9 +810,9 @@
 86                                                  DEFAULT_ENV_HEAD)
 87                   search_dir(instances, pattern, serverid)
 88                   if self.verbose and len(instances) > 0:
 89 -                     self.log.info("List from %s" % privconfig_head)
 90 +                     self.log.info("List from %s", privconfig_head)
 91                       for instance in instances:
 92 -                         self.log.info("list instance %r\n" % instance)
 93 +                         self.log.info("list instance %r\n", instance)
 94   
 95           else:
 96               # all instances must be retrieved
 97 @@ -821,16 +821,16 @@
 98                                                  DEFAULT_ENV_HEAD)
 99                   search_dir(instances, pattern)
100                   if self.verbose and len(instances) > 0:
101 -                     self.log.info("List from %s" % privconfig_head)
102 +                     self.log.info("List from %s", privconfig_head)
103                       for instance in instances:
104 -                         self.log.info("list instance %r\n" % instance)
105 +                         self.log.info("list instance %r\n", instance)
106   
107               pattern = "%s*" % os.path.join(sysconfig_head, DEFAULT_ENV_HEAD)
108               search_dir(instances, pattern)
109               if self.verbose and len(instances) > 0:
110 -                 self.log.info("List from %s" % privconfig_head)
111 +                 self.log.info("List from %s", privconfig_head)
112                   for instance in instances:
113 -                     self.log.info("list instance %r\n" % instance)
114 +                     self.log.info("list instance %r\n", instance)
115   
116           return instances
117   
118 @@ -862,7 +862,7 @@
119           prog = os.path.join(self.ds_paths.sbin_dir, CMD_PATH_SETUP_DS)
120   
121           if not os.path.isfile(prog):
122 -             self.log.error("Can't find file: %r, removing extension" % prog)
123 +             self.log.error("Can't find file: %r, removing extension", prog)
124               prog = prog[:-3]
125   
126           # Create and extract a service keytab
127 @@ -943,7 +943,7 @@
128                                   instance with the same 'serverid'
129           """
130           # check that DirSrv was in DIRSRV_STATE_ALLOCATED state
131 -         self.log.debug("Server is in state %s" % self.state)
132 +         self.log.debug("Server is in state %s", self.state)
133           if self.state != DIRSRV_STATE_ALLOCATED:
134               raise ValueError("invalid state for calling create: %s" %
135                                self.state)
136 @@ -999,11 +999,11 @@
137           if (not self.ds_paths.prefix or self.ds_paths.prefix == '/') and os.geteuid() != 0:
138               raise ValueError("Error: without prefix deployment it is required to be root user")
139           cmd = "%s -i %s%s" % (prog, DEFAULT_INST_HEAD, self.serverid)
140 -         self.log.debug("running: %s " % cmd)
141 +         self.log.debug("running: %s ", cmd)
142           try:
143               os.system(cmd)
144           except:
145 -             self.log.exception("error executing %r" % cmd)
146 +             self.log.exception("error executing %r", cmd)
147   
148           # If this was the last instance being deleted, remove the DEFAULT_USER
149           # if lib389 created the default user
150 @@ -1017,7 +1017,8 @@
151                       try:
152                           subprocess.call(cmd)
153                       except subprocess.CalledProcessError as e:
154 -                         self.log.exception('Failed to delete default user ' +
155 +                         self.log.exception(
156 +                                 'Failed to delete default user ',
157                                         '(%s): error %s' % (DEFAULT_USER,
158                                                             e.output))
159   
160 @@ -1059,7 +1060,7 @@
161           if not uri:
162               uri = self.toLDAPURL()
163   
164 -         self.log.debug('open(): Connecting to uri %s' % uri)
165 +         self.log.debug('open(): Connecting to uri %s', uri)
166           if hasattr(ldap, 'PYLDAP_VERSION') and MAJOR >= 3:
167               super(DirSrv, self).__init__(uri, bytes_mode=False, trace_level=TRACE_LEVEL)
168           else:
169 @@ -1067,7 +1068,7 @@
170   
171           if certdir is None and self.isLocal:
172               certdir = self.get_cert_dir()
173 -             self.log.debug("Using dirsrv ca certificate %s" % certdir)
174 +             self.log.debug("Using dirsrv ca certificate %s", certdir)
175   
176           if certdir is not None:
177               """
178 @@ -1076,20 +1077,20 @@
179               # Note this sets LDAP.OPT not SELF. Because once self has opened
180               # it can NOT change opts AT ALL.
181               self.set_option(ldap.OPT_X_TLS_CACERTDIR, ensure_str(certdir))
182 -             self.log.debug("Using external ca certificate %s" % certdir)
183 +             self.log.debug("Using external ca certificate %s", certdir)
184   
185           if userkey is not None:
186               # Note this sets LDAP.OPT not SELF. Because once self has opened
187               # it can NOT change opts AT ALL.
188 -             self.log.debug("Using user private key %s" % userkey)
189 +             self.log.debug("Using user private key %s", userkey)
190               self.set_option(ldap.OPT_X_TLS_KEYFILE, ensure_str(userkey))
191   
192           if usercert is not None:
193 -             self.log.debug("Using user certificate %s" % usercert)
194 +             self.log.debug("Using user certificate %s", usercert)
195               self.set_option(ldap.OPT_X_TLS_CERTFILE, ensure_str(usercert))
196   
197           if certdir is not None:
198 -             self.log.debug("Using external ca certificate %s" % certdir)
199 +             self.log.debug("Using external ca certificate %s", certdir)
200               self.set_option(ldap.OPT_X_TLS_CACERTDIR, ensure_str(certdir))
201   
202           if certdir or starttls:
203 @@ -1097,10 +1098,10 @@
204                   # Note this sets LDAP.OPT not SELF. Because once self has opened
205                   # it can NOT change opts on reused (ie restart)
206                   self.set_option(ldap.OPT_X_TLS_REQUIRE_CERT, reqcert)
207 -                 self.log.debug("Using certificate policy %s" % reqcert)
208 -                 self.log.debug("ldap.OPT_X_TLS_REQUIRE_CERT = %s" % reqcert)
209 +                 self.log.debug("Using certificate policy %s", reqcert)
210 +                 self.log.debug("ldap.OPT_X_TLS_REQUIRE_CERT = %s", reqcert)
211               except ldap.LDAPError as e:
212 -                 self.log.fatal('TLS negotiation failed: %s' % str(e))
213 +                 self.log.fatal('TLS negotiation failed: %s', e)
214                   raise e
215   
216           # Tell python ldap to make a new TLS context with this information.
217 @@ -1125,7 +1126,7 @@
218               self.sasl_interactive_bind_s("", sasl_auth)
219           elif saslmethod:
220               # Unknown or unsupported method
221 -             self.log.debug('Unsupported SASL method: %s' % saslmethod)
222 +             self.log.debug('Unsupported SASL method: %s', saslmethod)
223               raise ldap.UNWILLING_TO_PERFORM
224   
225           elif self.can_autobind():
226 @@ -1144,17 +1145,17 @@
227                   self.simple_bind_s(ensure_str(self.binddn), self.bindpw)
228               except ldap.SERVER_DOWN as e:
229                   # TODO add server info in exception
230 -                 self.log.debug("Cannot connect to %r" % uri)
231 +                 self.log.debug("Cannot connect to %r", uri)
232                   raise e
233               except ldap.LDAPError as e:
234 -                 self.log.debug("Error: Failed to authenticate: %s", str(e))
235 +                 self.log.debug("Error: Failed to authenticate: %s", e)
236                   raise e
237   
238           """
239           Authenticated, now finish the initialization
240           """
241           if self.verbose:
242 -             self.log.info("open(): bound as %s" % self.binddn)
243 +             self.log.info("open(): bound as %s", self.binddn)
244           if not connOnly:
245               self.__initPart2()
246           self.state = DIRSRV_STATE_ONLINE
247 @@ -1298,20 +1299,20 @@
248               # TODO: use the status call instead!!!!
249               pid = pid_from_file(self.ds_paths.pid_file)
250               if pid is None:
251 -                 self.log.debug("No pidfile found for %s" % self.serverid)
252 +                 self.log.debug("No pidfile found for %s", self.serverid)
253                   # No pidfile yet ...
254                   self.state = DIRSRV_STATE_OFFLINE
255                   return False
256               if pid == 0:
257 -                 self.log.debug("Pid of 0 not valid for %s" % self.serverid)
258 +                 self.log.debug("Pid of 0 not valid for %s", self.serverid)
259                   self.state = DIRSRV_STATE_OFFLINE
260                   raise ValueError
261               # Wait
262               if not pid_exists(pid):
263 -                 self.log.debug("Pid of %s is not running for %s" % (pid, self.serverid))
264 +                 self.log.debug("Pid of %s is not running for %s", pid, self.serverid)
265                   self.state = DIRSRV_STATE_OFFLINE
266                   return False
267 -             self.log.debug("Pid of %s for %s and running" % (pid, self.serverid))
268 +             self.log.debug("Pid of %s for %s and running", pid, self.serverid)
269               return True
270   
271       def restart(self, timeout=120, post_open=True):
272 @@ -1359,7 +1360,7 @@
273                   try:
274                       os.remove(backup_file)
275                   except:
276 -                     self.log.info("clearBackupFS: fail to remove %s" % backup_file)
277 +                     self.log.info("clearBackupFS: fail to remove %s", backup_file)
278                       pass
279           else:
280               backup_dir, backup_pattern = self._infoBackupFS()
281 @@ -1368,7 +1369,7 @@
282                   try:
283                       os.remove(f)
284                   except:
285 -                     self.log.info("clearBackupFS: fail to remove %s" % backup_file)
286 +                     self.log.info("clearBackupFS: fail to remove %s", backup_file)
287                       pass
288   
289       def checkBackupFS(self):
290 @@ -1463,15 +1464,15 @@
291   
292                   for b_dir in dirs:
293                       name = os.path.join(root, b_dir)
294 -                     self.log.debug("backupFS b_dir = %s (%s) [name=%s]" %
295 -                               (b_dir, self.ds_paths.prefix, name))
296 +                     self.log.debug("backupFS b_dir = %s (%s) [name=%s]",
297 +                                    b_dir, self.ds_paths.prefix, name)
298                       if prefix_pattern:
299                           name = re.sub(prefix_pattern, '', name)
300   
301                       if os.path.isdir(name):
302                           listFilesToBackup.append(name)
303 -                         self.log.debug("backupFS add = %s (%s)" %
304 -                                   (name, self.ds_paths.prefix))
305 +                         self.log.debug("backupFS add = %s (%s)",
306 +                                        name, self.ds_paths.prefix)
307   
308                   for file in files:
309                       name = os.path.join(root, file)
310 @@ -1480,8 +1481,8 @@
311   
312                       if os.path.isfile(name):
313                           listFilesToBackup.append(name)
314 -                         self.log.debug("backupFS add = %s (%s)" %
315 -                                   (name, self.ds_paths.prefix))
316 +                         self.log.debug("backupFS add = %s (%s)",
317 +                                        name, self.ds_paths.prefix)
318   
319           # create the archive
320           name = "backup_%s_%s.tar.gz" % (self.serverid, time.strftime("%m%d%Y_%H%M%S"))
321 @@ -1491,7 +1492,7 @@
322           for name in listFilesToBackup:
323               tar.add(name)
324           tar.close()
325 -         self.log.info("backupFS: archive done : %s" % backup_file)
326 +         self.log.info("backupFS: archive done : %s", backup_file)
327   
328           # return to the directory where we were
329           os.chdir(here)
330 @@ -1514,7 +1515,7 @@
331               self.log.warning("Unable to restore the instance (missing backup)")
332               raise ValueError("Unable to restore the instance (missing backup)")
333           if not os.path.isfile(backup_file):
334 -             self.log.warning("Unable to restore the instance (%s is not a file)" %
335 +             self.log.warning("Unable to restore the instance (%s is not a file)",
336                           backup_file)
337               raise ValueError("Unable to restore the instance " +
338                                "(%s is not a file)" % backup_file)
339 @@ -1524,26 +1525,26 @@
340           #
341   
342           # previous db (it may exists new db files not in the backup)
343 -         self.log.debug("restoreFS: remove subtree %s/*" % os.path.dirname(self.dbdir))
344 +         self.log.debug("restoreFS: remove subtree %s/*", os.path.dirname(self.dbdir))
345           for root, dirs, files in os.walk(os.path.dirname(self.dbdir)):
346               for d in dirs:
347                   if d not in ("bak", "ldif"):
348 -                     self.log.debug("restoreFS: before restore remove directory" +
349 -                               " %s/%s" % (root, d))
350 +                     self.log.debug("restoreFS: before restore remove directory"
351 +                                    " %s/%s", root, d)
352                       shutil.rmtree("%s/%s" % (root, d))
353   
354           # previous error/access logs
355 -         self.log.debug("restoreFS: remove error logs %s" % self.errlog)
356 +         self.log.debug("restoreFS: remove error logs %s", self.errlog)
357           for f in glob.glob("%s*" % self.errlog):
358 -             self.log.debug("restoreFS: before restore remove file %s" % (f))
359 +             self.log.debug("restoreFS: before restore remove file %s", f)
360               os.remove(f)
361 -         self.log.debug("restoreFS: remove access logs %s" % self.accesslog)
362 +         self.log.debug("restoreFS: remove access logs %s", self.accesslog)
363           for f in glob.glob("%s*" % self.accesslog):
364 -             self.log.debug("restoreFS: before restore remove file %s" % (f))
365 +             self.log.debug("restoreFS: before restore remove file %s", f)
366               os.remove(f)
367           log.debug("restoreFS: remove audit logs %s" % self.accesslog)
368           for f in glob.glob("%s*" % self.auditlog):
369 -             self.log.debug("restoreFS: before restore remove file %s" % (f))
370 +             self.log.debug("restoreFS: before restore remove file %s", f)
371               os.remove(f)
372   
373           # Then restore from the directory where DS was deployed
374 @@ -1563,13 +1564,13 @@
375                   # It could be a bad idea and preferably restore all.
376                   # Now it will be easy to enhance that function.
377                   if os.access(member.name, os.W_OK):
378 -                     self.log.debug("restoreFS: restored %s" % member.name)
379 +                     self.log.debug("restoreFS: restored %s", member.name)
380                       tar.extract(member.name)
381                   else:
382 -                     self.log.debug("restoreFS: not restored %s (no write access)" %
383 -                               member.name)
384 +                     self.log.debug("restoreFS: not restored %s (no write access)",
385 +                                    member.name)
386               else:
387 -                 self.log.debug("restoreFS: restored %s" % member.name)
388 +                 self.log.debug("restoreFS: restored %s", member.name)
389                   tar.extract(member.name)
390   
391           tar.close()
392 @@ -1580,10 +1581,10 @@
393           guardian_file = os.path.join(self.dbdir, "guardian")
394           if os.path.isfile(guardian_file):
395               try:
396 -                 self.log.debug("restoreFS: remove %s" % guardian_file)
397 +                 self.log.debug("restoreFS: remove %s", guardian_file)
398                   os.remove(guardian_file)
399               except:
400 -                 self.log.warning("restoreFS: fail to remove %s" % guardian_file)
401 +                 self.log.warning("restoreFS: fail to remove %s", guardian_file)
402                   pass
403   
404           os.chdir(here)
405 @@ -1799,7 +1800,7 @@
406               XXX This cannot return None
407           """
408           if self.verbose:
409 -             self.log.debug("Retrieving entry with %r" % [args])
410 +             self.log.debug("Retrieving entry with %r", [args])
411           if len(args) == 1 and 'scope' not in kwargs:
412               args += (ldap.SCOPE_BASE, )
413   
414 @@ -1807,10 +1808,10 @@
415           restype, obj = self.result(res)
416           # TODO: why not test restype?
417           if not obj:
418 -             raise NoSuchEntryError("no such entry for %r" % [args])
419 +             raise NoSuchEntryError("no such entry for %r", [args])
420   
421           if self.verbose:
422 -             self.log.info("Retrieved entry %s" % obj)
423 +             self.log.info("Retrieved entry %s", obj)
424           if isinstance(obj, Entry):
425               return obj
426           else:  # assume list/tuple
427 @@ -1821,13 +1822,13 @@
428       def _test_entry(self, dn, scope=ldap.SCOPE_BASE):
429           try:
430               entry = self.getEntry(dn, scope)
431 -             self.log.info("Found entry %s" % entry)
432 +             self.log.info("Found entry %s", entry)
433               return entry
434           except NoSuchEntryError:
435 -             self.log.exception("Entry %s was added successfully, but I cannot " +
436 -                           "search it" % dn)
437 -             raise MissingEntryError("Entry %s was added successfully, but " +
438 -                                     "I cannot search it" % dn)
439 +             self.log.exception("Entry %s was added successfully, but I cannot ",
440 +                                "search it" % dn)
441 +             raise MissingEntryError("Entry %s was added successfully, but "
442 +                                     "I cannot search it", dn)
443   
444       def __wrapmethods(self):
445           """This wraps all methods of SimpleLDAPObject, so that we can intercept
446 @@ -1865,7 +1866,7 @@
447                   except ldap.LDAPError as e:
448                       if not self.cont:
449                           raise e
450 -                     self.log.exception("Error: could not add entry %s" % dn)
451 +                     self.log.exception("Error: could not add entry %s", dn)
452   
453           adder = LDIFAdder(input_file, self, cont)
454   
455 @@ -2091,8 +2092,8 @@
456                         "userdn = \"ldap:///%s\";)" % binddn)
457               self.modify_s(suffix, [(ldap.MOD_ADD, 'aci', [acival])])
458           except ldap.TYPE_OR_VALUE_EXISTS:
459 -             self.log.error("proxy aci already exists in suffix %s for %s" % (
460 -                 suffix, binddn))
461 +             self.log.error("proxy aci already exists in suffix %s for %s",
462 +                            suffix, binddn)
463   
464       def setupChaining(self, to, suffix, isIntermediate):
465           """Setup chaining from self to to - self is the mux, to is the farm
466 @@ -2176,7 +2177,7 @@
467           try:
468               self.add_s(ent)
469           except ldap.ALREADY_EXISTS:
470 -             self.log.warn("Entry %s already exists" % binddn)
471 +             self.log.warn("Entry %s already exists", binddn)
472   
473           try:
474               entry = self._test_entry(binddn, ldap.SCOPE_BASE)
475 @@ -2259,8 +2260,8 @@
476                   # weird, internal error we do not retrieve the default
477                   # replication bind DN this replica agreement will fail
478                   # to update the consumer until the property will be set
479 -                 self.log.warning("createAgreement: binddn not provided and " +
480 -                             "default value unavailable")
481 +                 self.log.warning("createAgreement: binddn not provided and "
482 +                                  "default value unavailable")
483                   pass
484   
485           # get the RA binddn password
486 @@ -2272,8 +2273,8 @@
487                   # replication bind DN password this replica agreement
488                   # will fail to update the consumer until the property will be
489                   # set
490 -                 self.log.warning("createAgreement: bindpw not provided and " +
491 -                             "default value unavailable")
492 +                 self.log.warning("createAgreement: bindpw not provided and "
493 +                                  "default value unavailable")
494                   pass
495   
496           # get the RA bind method
497 @@ -2284,8 +2285,8 @@
498                   # weird, internal error we do not retrieve the default
499                   # replication bind method this replica agreement will
500                   # fail to update the consumer until the property will be set
501 -                 self.log.warning("createAgreement: bindmethod not provided and " +
502 -                             "default value unavailable")
503 +                 self.log.warning("createAgreement: bindmethod not provided and "
504 +                                  "default value unavailable")
505                   pass
506   
507           nsuffix = normalizeDN(suffix)
508 @@ -2357,7 +2358,7 @@
509               self.setupWinSyncAgmt(args, entry)
510   
511           try:
512 -             self.log.debug("Adding replica agreement: [%s]" % entry)
513 +             self.log.debug("Adding replica agreement: [%s]", entry)
514               self.add_s(entry)
515           except:
516               #  TODO check please!
517 @@ -2441,13 +2442,13 @@
518                           replicated = True
519                           break
520                   except ldap.LDAPError as e:
521 -                     self.log.fatal('testReplication() failed to modify (%s), error (%s)' % (suffix, str(e)))
522 +                     self.log.fatal('testReplication() failed to modify (%s), error (%s)', suffix, e)
523                       return False
524                   loop += 1
525                   time.sleep(2)
526               if not replicated:
527 -                 self.log.fatal('Replication is not in sync with replica server (%s)'
528 -                           % replica.serverid)
529 +                 self.log.fatal('Replication is not in sync with replica server (%s)',
530 +                                replica.serverid)
531                   return False
532   
533           return True
534 @@ -2512,7 +2513,7 @@
535                   })
536               self.setupBindDN(*attrs)
537           except ldap.ALREADY_EXISTS:
538 -             self.log.warn("User already exists: %r " % user)
539 +             self.log.warn("User already exists: %r ", user)
540   
541           # setup replica
542           # map old style args to new style replica args
543 @@ -2719,7 +2720,7 @@
544   
545                   return
546   
547 -         self.log.fatal('Failed to clear tmp directory (%s)' % filename)
548 +         self.log.fatal('Failed to clear tmp directory (%s)', filename)
549   
550       def upgrade(self, upgradeMode):
551           """
552 @@ -2757,7 +2758,7 @@
553               return False
554   
555           if not os.path.isfile(import_file):
556 -             self.log.error("ldif2db: Can't find file: %s" % import_file)
557 +             self.log.error("ldif2db: Can't find file: %s", import_file)
558               return False
559   
560           cmd = [
561 @@ -2784,8 +2785,8 @@
562           try:
563               result = subprocess.check_output(cmd, encoding='utf-8')
564           except subprocess.CalledProcessError as e:
565 -             self.log.debug("Command: {} failed with the return code {} and the error {}".format(
566 -                            format_cmd_list(cmd), e.returncode, e.output))
567 +             self.log.debug("Command: %s failed with the return code %s and the error %s",
568 +                            format_cmd_list(cmd), e.returncode, e.output)
569               return False
570   
571           self.log.debug("ldif2db output: BEGIN")
572 @@ -2852,8 +2853,8 @@
573           try:
574               result = subprocess.check_output(cmd, encoding='utf-8')
575           except subprocess.CalledProcessError as e:
576 -             self.log.debug("Command: {} failed with the return code {} and the error {}".format(
577 -                            format_cmd_list(cmd), e.returncode, e.output))
578 +             self.log.debug("Command: %s failed with the return code %s and the error %s",
579 +                            format_cmd_list(cmd), e.returncode, e.output)
580               return False
581   
582           self.log.debug("db2ldif output: BEGIN")
583 @@ -2888,8 +2889,8 @@
584                   '-D', self.get_config_dir()
585               ], encoding='utf-8')
586           except subprocess.CalledProcessError as e:
587 -             self.log.debug("Command: {} failed with the return code {} and the error {}".format(
588 -                            format_cmd_list(cmd), e.returncode, e.output))
589 +             self.log.debug("Command: %s failed with the return code %s and the error %s",
590 +                            format_cmd_list(cmd), e.returncode, e.output)
591               return False
592   
593           self.log.debug("bak2db output: BEGIN")
594 @@ -2926,8 +2927,8 @@
595                   '-D', self.get_config_dir()
596               ], encoding='utf-8')
597           except subprocess.CalledProcessError as e:
598 -             self.log.debug("Command: {} failed with the return code {} and the error {}".format(
599 -                            format_cmd_list(cmd), e.returncode, e.output))
600 +             self.log.debug("Command: %s failed with the return code %s and the error %s",
601 +                            format_cmd_list(cmd), e.returncode, e.output)
602               return False
603   
604           self.log.debug("db2bak output: BEGIN")
605 @@ -2989,8 +2990,8 @@
606           try:
607               result = subprocess.check_output(cmd, encoding='utf-8')
608           except subprocess.CalledProcessError as e:
609 -             self.log.debug("Command: {} failed with the return code {} and the error {}".format(
610 -                            format_cmd_list(cmd), e.returncode, e.output))
611 +             self.log.debug("Command: %s failed with the return code %s and the error %s",
612 +                            format_cmd_list(cmd), e.returncode, e.output)
613               return False
614   
615           self.log.debug("db2index output: BEGIN")
616 @@ -3015,7 +3016,7 @@
617                   json_item = [backup, bak_date, bak_size]
618                   json_result['items'].append(json_item)
619               else:
620 -                 self.log.info('Backup: {} - {} ({})'.format(bak, bak_date, bak_size))
621 +                 self.log.info('Backup: %s - %s (%s)', bak, bak_date, bak_size)
622   
623           if use_json:
624               print(json.dumps(json_result))
625 @@ -3026,7 +3027,7 @@
626           # Delete backup directory
627           bakdir = self.get_bak_dir()
628           del_dir = bakdir + "/" + bak_dir
629 -         self.log.debug("Deleting backup directory: " + del_dir)
630 +         self.log.debug("Deleting backup directory: ", del_dir)
631           shutil.rmtree(del_dir)
632   
633       def dbscan(self, bename=None, index=None, key=None, width=None, isRaw=False):
634 @@ -3074,7 +3075,7 @@
635   
636           self.stop(timeout=10)
637   
638 -         self.log.info('Running script: %s' % cmd)
639 +         self.log.info('Running script: %s', cmd)
640           output = subprocess.check_output(cmd)
641   
642           self.start(timeout=10)
643 @@ -3278,8 +3279,8 @@
644                       gid = grp.getgrnam(self.userid).gr_gid
645                       os.chown(ldif_file, uid, gid)
646               except OSError as e:
647 -                 self.log.exception('Failed to create ldif file (%s): error %d - %s' %
648 -                               (ldif_file, e.errno, e.strerror))
649 +                 self.log.exception('Failed to create ldif file (%s): error %d - %s',
650 +                                    ldif_file, e.errno, e.strerror)
651                   raise e
652   
653       def getConsumerMaxCSN(self, replica_entry):
654 @@ -3302,8 +3303,8 @@
655           try:
656               consumer.open()
657           except ldap.LDAPError as e:
658 -             self.log.debug('Connection to consumer (%s:%s) failed, error: %s' %
659 -                            (host, port, str(e)))
660 +             self.log.debug('Connection to consumer (%s:%s) failed, error: %s',
661 +                            host, port, e)
662               return error_msg
663   
664           # Get the replica id from supplier to compare to the consumer's rid
665 @@ -3407,5 +3408,5 @@
666           ents = self.search_s(basedn, scope, filterstr)
667   
668           for ent in sorted(ents, key=lambda e: len(e.dn), reverse=True):
669 -             self.log.debug("Delete entry children %s" % (ent.dn))
670 +             self.log.debug("Delete entry children %s", ent.dn)
671               self.delete_ext_s(ent.dn, serverctrls=serverctrls, clientctrls=clientctrls)
 1 @@ -336,7 +336,7 @@
 2               raise
 3   
 4           # update it
 5 -         self.log.info("Schedule replication agreement %s" % agmtdn)
 6 +         self.log.info("Schedule replication agreement %s", agmtdn)
 7           mod = [(ldap.MOD_REPLACE, 'nsds5replicaupdateschedule', [ensure_bytes(interval)])]
 8           self.conn.modify_s(agmtdn, mod)
 9   
10 @@ -436,12 +436,12 @@
11               if not inProperties(prop, RA_PROPNAME_TO_ATTRNAME):
12                   raise ValueError("unknown property: %s" % prop)
13               else:
14 -                 self.log.debug("setProperties: %s:%s" %
15 -                                (prop, properties[prop]))
16 +                 self.log.debug("setProperties: %s:%s",
17 +                                prop, properties[prop])
18   
19           # At least we need to have suffix/agmnt_dn/agmnt_entry
20           if not suffix and not agmnt_dn and not agmnt_entry:
21 -             raise InvalidArgumentError("suffix and agmnt_dn and agmnt_entry " +
22 +             raise InvalidArgumentError("suffix and agmnt_dn and agmnt_entry "
23                                          "are missing")
24   
25           # TODO
26 @@ -634,7 +634,7 @@
27           # we can just raise ALREADY_EXISTS
28           try:
29               entry = self.conn.getEntry(dn_agreement, ldap.SCOPE_BASE)
30 -             self.log.warn("Agreement already exists: %r" % dn_agreement)
31 +             self.log.warn("Agreement already exists: %r", dn_agreement)
32               return dn_agreement
33           except ldap.NO_SUCH_OBJECT:
34               entry = None
35 @@ -657,10 +657,10 @@
36               self.conn.setupWinSyncAgmt(propertiescopy, entry)
37   
38           try:
39 -             self.log.debug("Adding replica agreement: [%r]" % entry)
40 +             self.log.debug("Adding replica agreement: [%r]", entry)
41               self.conn.add_s(entry)
42           except ldap.LDAPError as e:
43 -             self.log.fatal('Failed to add replication agreement: %s' % str(e))
44 +             self.log.fatal('Failed to add replication agreement: %s', e)
45               raise e
46   
47           entry = self.conn.waitForEntry(dn_agreement)
48 @@ -728,10 +728,10 @@
49                   try:
50                       agmt_dn = agmts[0].dn
51                       self.conn.delete_s(agmt_dn)
52 -                     self.log.info('Agreement (%s) was successfully removed' % agmt_dn)
53 +                     self.log.info('Agreement (%s) was successfully removed', agmt_dn)
54                   except ldap.LDAPError as e:
55 -                     self.log.error('Failed to delete agreement (%s), ' +
56 -                                    'error: %s' % (agmt_dn, str(e)))
57 +                     self.log.error('Failed to delete agreement (%s), '
58 +                                    'error: %s', agmt_dn, e)
59                       raise
60           else:
61               raise NoSuchEntryError('No agreements were found')
62 @@ -777,8 +777,8 @@
63               raise NoSuchEntryError(
64                   "Error: no replica set up for suffix " + suffix)
65           replica_entry = replica_entries[0]
66 -         self.log.debug("initAgreement: looking for replica agreements " +
67 -                        "under %s" % replica_entry.dn)
68 +         self.log.debug("initAgreement: looking for replica agreements "
69 +                        "under %s", replica_entry.dn)
70           try:
71               '''
72               Currently python does not like long continuous lines when it
73 @@ -802,7 +802,7 @@
74           #
75           # trigger the total init
76           #
77 -         self.log.info("Starting total init %s" % entry.dn)
78 +         self.log.info("Starting total init %s", entry.dn)
79           mod = [(ldap.MOD_ADD, 'nsds5BeginReplicaRefresh', ensure_bytes('start'))]
80           self.conn.modify_s(entry.dn, mod)
81   
82 @@ -827,7 +827,7 @@
83           :raises: ValueError - if interval is not valid
84           """
85   
86 -         self.log.info("Pausing replication %s" % agmtdn)
87 +         self.log.info("Pausing replication %s", agmtdn)
88           mod = [(ldap.MOD_REPLACE, 'nsds5ReplicaEnabled', [b'off'])]
89           self.conn.modify_s(ensure_str(agmtdn), mod)
90   
91 @@ -853,7 +853,7 @@
92                     - ldap.NO_SUCH_OBJECT - if agmtdn does not exist
93           """
94   
95 -         self.log.info("Resuming replication %s" % agmtdn)
96 +         self.log.info("Resuming replication %s", agmtdn)
97           mod = [(ldap.MOD_REPLACE, 'nsds5ReplicaEnabled', [b'on'])]
98           self.conn.modify_s(ensure_str(agmtdn), mod)
99   
 1 @@ -64,11 +64,11 @@
 2   
 3           filt = "(objectclass=%s)" % BACKEND_OBJECTCLASS_VALUE
 4           if backend_dn:
 5 -             self.log.info("List backend %s" % backend_dn)
 6 +             self.log.info("List backend %s", backend_dn)
 7               base = backend_dn
 8               scope = ldap.SCOPE_BASE
 9           elif suffix:
10 -             self.log.info("List backend with suffix=%s" % suffix)
11 +             self.log.info("List backend with suffix=%s", suffix)
12               base = DN_PLUGIN
13               scope = ldap.SCOPE_SUBTREE
14               filt = ("(&%s(|(%s=%s)(%s=%s)))" %
15 @@ -78,7 +78,7 @@
16                        normalizeDN(suffix))
17                       )
18           elif bename:
19 -             self.log.info("List backend 'cn=%s'" % bename)
20 +             self.log.info("List backend 'cn=%s'", bename)
21               base = "%s=%s,%s" % (BACKEND_PROPNAME_TO_ATTRNAME[BACKEND_NAME],
22                                    bename, DN_LDBM)
23               scope = ldap.SCOPE_BASE
24 @@ -155,7 +155,7 @@
25                   (suffix, backend_dn, bename))
26           elif len(be_ents) > 1:
27               for ent in be_ents:
28 -                 self.log.fatal("Multiple backend match the definition: %s" %
29 +                 self.log.fatal("Multiple backend match the definition: %s",
30                                  ent.dn)
31               if (not suffix) and (not backend_dn) and (not bename):
32                   raise ldap.UNWILLING_TO_PERFORM(
33 @@ -193,10 +193,10 @@
34           # finally delete the backend children and the backend itself
35           ents = self.conn.search_s(be_ent.dn, ldap.SCOPE_ONELEVEL)
36           for ent in ents:
37 -             self.log.debug("Delete entry children %s" % (ent.dn))
38 +             self.log.debug("Delete entry children %s", ent.dn)
39               self.conn.delete_s(ent.dn)
40   
41 -         self.log.debug("Delete backend entry %s" % (be_ent.dn))
42 +         self.log.debug("Delete backend entry %s", be_ent.dn)
43           self.conn.delete_s(be_ent.dn)
44   
45           return
46 @@ -246,12 +246,12 @@
47                           (BACKEND_PROPNAME_TO_ATTRNAME[BACKEND_NAME],
48                            bename, parent))
49                   filt = "(objectclass=%s)" % BACKEND_OBJECTCLASS_VALUE
50 -                 self.log.debug("_getBackendName: baser=%s : fileter=%s" %
51 -                                (base, filt))
52 +                 self.log.debug("_getBackendName: baser=%s : fileter=%s",
53 +                                base, filt)
54                   try:
55                       self.conn.getEntry(base, ldap.SCOPE_BASE, filt)
56                   except (NoSuchEntryError, ldap.NO_SUCH_OBJECT):
57 -                     self.log.info("backend name will be %s" % bename)
58 +                     self.log.info("backend name will be %s", bename)
59                       return bename
60                   index += 1
61   
62 @@ -265,7 +265,7 @@
63   
64           # Check it does not already exist a backend for that suffix
65           if self.conn.verbose:
66 -             self.log.info("Checking suffix %s for existence" % suffix)
67 +             self.log.info("Checking suffix %s for existence", suffix)
68           ents = self.conn.backend.list(suffix=suffix)
69           if len(ents) != 0:
70               raise ldap.ALREADY_EXISTS
71 @@ -317,13 +317,13 @@
72                        properties[BACKEND_CHAIN_BIND_PW]
73                        })
74   
75 -             self.log.debug("adding entry: %r" % entry)
76 +             self.log.debug("adding entry: %r", entry)
77               self.conn.add_s(entry)
78           except ldap.ALREADY_EXISTS as e:
79 -             self.log.error("Entry already exists: %r" % dn)
80 +             self.log.error("Entry already exists: %r", dn)
81               raise ldap.ALREADY_EXISTS("%s : %r" % (e, dn))
82           except ldap.LDAPError as e:
83 -             self.log.error("Could not add backend entry: %r" % dn)
84 +             self.log.error("Could not add backend entry: %r", dn)
85               raise e
86   
87           backend_entry = self.conn._test_entry(dn, ldap.SCOPE_BASE)
88 @@ -365,7 +365,7 @@
89   
90               attrs = [attr_suffix]
91               ent = self.conn.getEntry(name, ldap.SCOPE_BASE, filt, attrs)
92 -             self.log.debug("toSuffix: %s found by its DN" % ent.dn)
93 +             self.log.debug("toSuffix: %s found by its DN", ent.dn)
94   
95               if not ent.hasValue(attr_suffix):
96                   raise ValueError("Entry has no %s attribute %r" %
 1 @@ -122,12 +122,12 @@
 2               CHANGELOG_PROPNAME_TO_ATTRNAME[CHANGELOG_NAME]: changelog_name,
 3               CHANGELOG_PROPNAME_TO_ATTRNAME[CHANGELOG_DIR]: dirpath
 4           })
 5 -         self.log.debug("adding changelog entry: %r" % entry)
 6 +         self.log.debug("adding changelog entry: %r", entry)
 7           self.conn.changelogdir = dirpath
 8           try:
 9               self.conn.add_s(entry)
10           except ldap.ALREADY_EXISTS:
11 -             self.log.warn("entry %s already exists" % dn)
12 +             self.log.warn("entry %s already exists", dn)
13           return dn
14   
15       def delete(self):
16 @@ -139,7 +139,7 @@
17           try:
18               self.conn.delete_s(DN_CHANGELOG)
19           except ldap.LDAPError as e:
20 -             self.log.error('Failed to delete the changelog: ' + str(e))
21 +             self.log.error('Failed to delete the changelog: %s', e)
22               raise
23   
24       def setProperties(self, changelogdn=None, properties=None):
1 @@ -208,7 +208,7 @@
2           }
3           # First, pull some well known info out.
4           if self.dirsrv.verbose:
5 -             self.log.info("--> %s " % line)
6 +             self.log.info("--> %s ", line)
7   
8           for regex in self.full_regexs:
9               result = regex.match(line)
1 @@ -76,7 +76,7 @@
2           self.conn.delete_branch_s(dn, ldap.SCOPE_ONELEVEL)
3   
4           # Then delete the top index entry
5 -         self.log.debug("Delete head index entry %s" % (dn))
6 +         self.log.debug("Delete head index entry %s", dn)
7           self.conn.delete_s(dn)
8   
9       def create(self, suffix=None, be_name=None, attr=None, args=None):
1 @@ -74,7 +74,7 @@
2                   err_msg = ('Invalid value in section "%s", "%s" has incorrect type (%s)' % (self._section, k, str(e)))
3                   raise ValueError(err_msg)
4               except configparser.NoOptionError:
5 -                 self.log.debug('%s:%s not in inf, using default' % (self._section, k))
6 +                 self.log.debug('%s:%s not in inf, using default', self._section, k)
7                   continue
8               self._options[k] = v
9   
  1 @@ -117,7 +117,7 @@
  2           except ValueError:
  3               return value
  4           except configparser.NoOptionError:
  5 -             self.log.info("%s not specified:setting to default - %s" % (attr, value))
  6 +             self.log.info("%s not specified:setting to default - %s", attr, value)
  7               return value
  8   
  9       def _validate_config_2(self, config):
 10 @@ -139,7 +139,7 @@
 11           general = general_options.collect()
 12   
 13           if self.verbose:
 14 -             self.log.info("Configuration general %s" % general)
 15 +             self.log.info("Configuration general %s", general)
 16   
 17           slapd_options = Slapd2Base(self.log)
 18           slapd_options.parse_inf_config(config)
 19 @@ -147,7 +147,7 @@
 20           slapd = slapd_options.collect()
 21   
 22           if self.verbose:
 23 -             self.log.info("Configuration slapd %s" % slapd)
 24 +             self.log.info("Configuration slapd %s", slapd)
 25   
 26           backends = []
 27           for section in config.sections():
 28 @@ -183,7 +183,7 @@
 29                       backends.append(be)
 30   
 31           if self.verbose:
 32 -             self.log.info("Configuration backends %s" % backends)
 33 +             self.log.info("Configuration backends %s", backends)
 34   
 35           return (general, slapd, backends)
 36   
 37 @@ -477,20 +477,20 @@
 38           """
 39           # Get the inf file
 40           if self.verbose:
 41 -             self.log.info("Using inf from %s" % inf_path)
 42 +             self.log.info("Using inf from %s", inf_path)
 43           if not os.path.isfile(inf_path):
 44 -             self.log.error("%s is not a valid file path" % inf_path)
 45 +             self.log.error("%s is not a valid file path", inf_path)
 46               return False
 47           config = None
 48           try:
 49               config = configparser.SafeConfigParser()
 50               config.read([inf_path])
 51           except Exception as e:
 52 -             self.log.error("Exception %s occured" % e)
 53 +             self.log.error("Exception %s occured", e)
 54               return False
 55   
 56           if self.verbose:
 57 -             self.log.info("Configuration %s" % config.sections())
 58 +             self.log.info("Configuration %s", config.sections())
 59   
 60           (general, slapd, backends) = self._validate_ds_config(config)
 61   
 62 @@ -503,7 +503,7 @@
 63   
 64           assert_c(general['defaults'] is not None, "Configuration defaults in section [general] not found")
 65           if self.verbose:
 66 -             self.log.info("PASSED: using config settings %s" % general['defaults'])
 67 +             self.log.info("PASSED: using config settings %s", general['defaults'])
 68           # Validate our arguments.
 69           assert_c(slapd['user'] is not None, "Configuration user in section [slapd] not found")
 70           # check the user exists
 71 @@ -572,7 +572,7 @@
 72           self._secure_password = password_hash(self._raw_secure_password, bin_dir=slapd['bin_dir'])
 73   
 74           if self.verbose:
 75 -             self.log.info("INFO: temp root password set to %s" % self._raw_secure_password)
 76 +             self.log.info("INFO: temp root password set to %s", self._raw_secure_password)
 77               self.log.info("PASSED: root user checking")
 78   
 79           assert_c(slapd['port'] is not None, "Configuration port in section [slapd] not found")
 80 @@ -596,14 +596,14 @@
 81   
 82           # Check we have privs to run
 83           if self.verbose:
 84 -             self.log.info("READY: Preparing installation for %s..." % slapd['instance_name'])
 85 +             self.log.info("READY: Preparing installation for %s...", slapd['instance_name'])
 86   
 87           self._prepare_ds(general, slapd, backends)
 88           # Call our child api to prepare itself.
 89           self._prepare(extra)
 90   
 91           if self.verbose:
 92 -             self.log.info("READY: Beginning installation for %s..." % slapd['instance_name'])
 93 +             self.log.info("READY: Beginning installation for %s...", slapd['instance_name'])
 94   
 95           if self.dryrun:
 96               self.log.info("NOOP: Dry run requested")
 97 @@ -613,9 +613,9 @@
 98               # Call the child api to do anything it needs.
 99               self._install(extra)
100           if self.verbose:
101 -             self.log.info("FINISH: Completed installation for %s" % slapd['instance_name'])
102 +             self.log.info("FINISH: Completed installation for %s", slapd['instance_name'])
103           else:
104 -             self.log.info("Completed installation for %s" % slapd['instance_name'])
105 +             self.log.info("Completed installation for %s", slapd['instance_name'])
106   
107       def _install_ds(self, general, slapd, backends):
108           """
109 @@ -649,7 +649,7 @@
110           # we should only need to make bak_dir, cert_dir, config_dir, db_dir, ldif_dir, lock_dir, log_dir, run_dir? schema_dir,
111           for path in ('backup_dir', 'cert_dir', 'config_dir', 'db_dir', 'ldif_dir', 'lock_dir', 'log_dir', 'run_dir'):
112               if self.verbose:
113 -                 self.log.info("ACTION: creating %s" % slapd[path])
114 +                 self.log.info("ACTION: creating %s", slapd[path])
115               try:
116                   os.makedirs(slapd[path], mode=0o775)
117               except OSError:
118 @@ -692,7 +692,7 @@
119   
120           # Create certdb in sysconfidir
121           if self.verbose:
122 -             self.log.info("ACTION: Creating certificate database is %s" % slapd['cert_dir'])
123 +             self.log.info("ACTION: Creating certificate database is %s", slapd['cert_dir'])
124   
125           # Create dse.ldif with a temporary root password.
126           # The template is in slapd['data_dir']/dirsrv/data/template-dse.ldif
  1 @@ -69,7 +69,7 @@
  2               ents = self.conn.search_s(DN_MAPPING_TREE, ldap.SCOPE_ONELEVEL,
  3                                         filt)
  4               for ent in ents:
  5 -                 self.log.debug('list: %r' % ent)
  6 +                 self.log.debug('list: %r', ent)
  7           except:
  8               raise
  9   
 10 @@ -151,8 +151,8 @@
 11               entry.setValues(MT_PROPNAME_TO_ATTRNAME[MT_PARENT_SUFFIX], nparent)
 12   
 13           try:
 14 -             self.log.debug("Creating entry: %s" % entry.dn)
 15 -             self.log.info("Entry %r" % entry)
 16 +             self.log.debug("Creating entry: %s", entry.dn)
 17 +             self.log.info("Entry %r", entry)
 18               self.conn.add_s(entry)
 19           except ldap.LDAPError as e:
 20               raise ldap.LDAPError("Error adding suffix entry " + dn, e)
 21 @@ -187,7 +187,7 @@
 22               filt = "(objectclass=%s)" % MT_OBJECTCLASS_VALUE
 23               try:
 24                   ent = self.conn.getEntry(name, ldap.SCOPE_BASE, filt)
 25 -                 self.log.debug("delete: %s found by its DN" % ent.dn)
 26 +                 self.log.debug("delete: %s found by its DN", ent.dn)
 27               except NoSuchEntryError:
 28                   raise ldap.NO_SUCH_OBJECT("mapping tree DN not found: %s" %
 29                                             name)
 30 @@ -210,7 +210,7 @@
 31               try:
 32                   ent = self.conn.getEntry(DN_MAPPING_TREE, ldap.SCOPE_ONELEVEL,
 33                                            filt)
 34 -                 self.log.debug("delete: %s found by with %s" % (ent.dn, filt))
 35 +                 self.log.debug("delete: %s found by with %s", ent.dn, filt)
 36               except NoSuchEntryError:
 37                   raise ldap.NO_SUCH_OBJECT("mapping tree DN not found: %s" %
 38                                             name)
 39 @@ -227,13 +227,13 @@
 40               raise
 41           if len(ents) != 1:
 42               for entry in ents:
 43 -                 self.log.warning("Error: it exists %s under %s" %
 44 -                                  (entry.dn, ent.dn))
 45 +                 self.log.warning("Error: it exists %s under %s",
 46 +                                  entry.dn, ent.dn)
 47               raise ldap.UNWILLING_TO_PERFORM(
 48                   "Unable to delete %s, it is not a leaf" % ent.dn)
 49           else:
 50               for entry in ents:
 51 -                 self.log.warning("Warning: %s (%s)" % (entry.dn, ent.dn))
 52 +                 self.log.warning("Warning: %s (%s)", entry.dn, ent.dn)
 53               self.conn.delete_s(ent.dn)
 54   
 55       def getProperties(self, suffix=None, bename=None, name=None,
 56 @@ -272,7 +272,7 @@
 57                   ent = self.conn.getEntry(name, ldap.SCOPE_BASE, filt,
 58                                            list(MT_PROPNAME_TO_ATTRNAME.values())
 59                                            )
 60 -                 self.log.debug("delete: %s found by its DN" % ent.dn)
 61 +                 self.log.debug("delete: %s found by its DN", ent.dn)
 62               except NoSuchEntryError:
 63                   raise ldap.NO_SUCH_OBJECT("mapping tree DN not found: %s" %
 64                                             name)
 65 @@ -296,7 +296,7 @@
 66                                            filt,
 67                                            list(MT_PROPNAME_TO_ATTRNAME.values())
 68                                            )
 69 -                 self.log.debug("delete: %s found by with %s" % (ent.dn, filt))
 70 +                 self.log.debug("delete: %s found by with %s", ent.dn, filt)
 71               except NoSuchEntryError:
 72                   raise ldap.NO_SUCH_OBJECT("mapping tree DN not found: %s" %
 73                                             name)
 74 @@ -311,8 +311,8 @@
 75                   prop_attr = MT_PROPNAME_TO_ATTRNAME[prop_name]
 76                   if not prop_attr:
 77                       raise ValueError("Improper property name: %s ", prop_name)
 78 -                 self.log.debug("Look for attr %s (property: %s)" %
 79 -                                (prop_attr, prop_name))
 80 +                 self.log.debug("Look for attr %s (property: %s)",
 81 +                                prop_attr, prop_name)
 82                   attrs.append(prop_attr)
 83   
 84           # now look for each attribute from the MT entry
 85 @@ -327,7 +327,7 @@
 86                   if len(attrs) > 0:
 87                       if MT_PROPNAME_TO_ATTRNAME[props[0]] in attrs:
 88                           # if the properties was requested
 89 -                         self.log.debug("keep only attribute %s " % (props[0]))
 90 +                         self.log.debug("keep only attribute %s ", props[0])
 91                           result[props[0]] = ent.getValues(attr)
 92                   else:
 93                       result[props[0]] = ent.getValues(attr)
 94 @@ -365,7 +365,7 @@
 95               try:
 96                   attrs = [attr_suffix]
 97                   ent = self.conn.getEntry(name, ldap.SCOPE_BASE, filt, attrs)
 98 -                 self.log.debug("toSuffix: %s found by its DN" % ent.dn)
 99 +                 self.log.debug("toSuffix: %s found by its DN", ent.dn)
100               except NoSuchEntryError:
101                   raise ldap.NO_SUCH_OBJECT("mapping tree DN not found: %s" %
102                                             name)
  1 @@ -133,9 +133,9 @@
  2           # 48886; This needs to be sql format ...
  3           cmd = ['/usr/bin/certutil', '-N', '-d', self._certdb, '-f', '%s/%s' % (self._certdb, PWD_TXT)]
  4           self._generate_noise('%s/noise.txt' % self._certdb)
  5 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
  6 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
  7           result = ensure_str(check_output(cmd, stderr=subprocess.STDOUT))
  8 -         self.log.debug("nss output: %s" % result)
  9 +         self.log.debug("nss output: %s", result)
 10           return True
 11   
 12       def _db_exists(self):
 13 @@ -198,9 +198,9 @@
 14               '-f',
 15               '%s/%s' % (self._certdb, PWD_TXT),
 16           ]
 17 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
 18 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
 19           result = ensure_str(check_output(cmd, stderr=subprocess.STDOUT))
 20 -         self.log.debug("nss output: %s" % result)
 21 +         self.log.debug("nss output: %s", result)
 22           # Now extract the CAcert to a well know place.
 23           # This allows us to point the cacert dir here and it "just works"
 24           cmd = [
 25 @@ -212,12 +212,12 @@
 26               self._certdb,
 27               '-a',
 28           ]
 29 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
 30 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
 31           certdetails = check_output(cmd, stderr=subprocess.STDOUT)
 32           with open('%s/ca.crt' % self._certdb, 'w') as f:
 33               f.write(ensure_str(certdetails))
 34           cmd = ['/usr/bin/c_rehash', self._certdb]
 35 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
 36 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
 37           check_output(cmd, stderr=subprocess.STDOUT)
 38           return True
 39   
 40 @@ -234,7 +234,7 @@
 41               '-d',
 42               self._certdb,
 43           ]
 44 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
 45 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
 46           certdetails = check_output(cmd, stderr=subprocess.STDOUT, encoding='utf-8')
 47           end_date_str = certdetails.split("Not After : ")[1].split("\n")[0]
 48           date_format = '%a %b %d %H:%M:%S %Y'
 49 @@ -273,7 +273,7 @@
 50               '-a',
 51               '-o', csr_path,
 52               ]
 53 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
 54 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
 55           check_output(cmd, stderr=subprocess.STDOUT)
 56   
 57           # Sign the CSR with our old CA
 58 @@ -295,11 +295,11 @@
 59               '-v',
 60               '%s' % months,
 61               ]
 62 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
 63 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
 64           check_output(cmd, stderr=subprocess.STDOUT)
 65   
 66           cmd = ['/usr/bin/c_rehash', self._certdb]
 67 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
 68 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
 69           check_output(cmd, stderr=subprocess.STDOUT)
 70   
 71           # Import the new CA to our DB instead of the old CA
 72 @@ -313,7 +313,7 @@
 73               '-d', self._certdb,
 74               '-f', '%s/%s' % (self._certdb, PWD_TXT),
 75               ]
 76 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
 77 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
 78           check_output(cmd, stderr=subprocess.STDOUT)
 79   
 80           return crt_path
 81 @@ -330,11 +330,11 @@
 82           result = ensure_str(check_output(cmd, stderr=subprocess.STDOUT))
 83   
 84           # We can skip the first few lines. They are junk
 85 -         # IE ['', 
 86 -         #     'Certificate Nickname                                         Trust Attributes', 
 87 -         #     '                                                             SSL,S/MIME,JAR/XPI', 
 88 -         #     '', 
 89 -         #     'Self-Signed-CA                                               CTu,u,u', 
 90 +         # IE ['',
 91 +         #     'Certificate Nickname                                         Trust Attributes',
 92 +         #     '                                                             SSL,S/MIME,JAR/XPI',
 93 +         #     '',
 94 +         #     'Self-Signed-CA                                               CTu,u,u',
 95           #     '']
 96           lines = result.split('\n')[4:-1]
 97           # Now make the lines usable
 98 @@ -354,7 +354,7 @@
 99               '-f',
100               '%s/%s' % (self._certdb, PWD_TXT),
101           ]
102 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
103 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
104           result = ensure_str(check_output(cmd, stderr=subprocess.STDOUT))
105   
106           lines = result.split('\n')[1:-1]
107 @@ -456,9 +456,9 @@
108               '-f',
109               '%s/%s' % (self._certdb, PWD_TXT),
110           ]
111 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
112 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
113           result = ensure_str(check_output(cmd, stderr=subprocess.STDOUT))
114 -         self.log.debug("nss output: %s" % result)
115 +         self.log.debug("nss output: %s", result)
116           return True
117   
118       def create_rsa_key_and_csr(self, alt_names=[]):
119 @@ -501,7 +501,7 @@
120               '-a',
121               '-o', csr_path,
122           ]
123 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
124 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
125           check_output(cmd, stderr=subprocess.STDOUT)
126   
127           return csr_path
128 @@ -527,7 +527,7 @@
129               '-o', crt_path,
130               '-c', CA_NAME,
131           ]
132 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
133 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
134           check_output(cmd, stderr=subprocess.STDOUT)
135   
136           return (ca_path, crt_path)
137 @@ -544,7 +544,7 @@
138           if ca is not None:
139               shutil.copyfile(ca, '%s/ca.crt' % self._certdb)
140               cmd = ['/usr/bin/c_rehash', self._certdb]
141 -             self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
142 +             self.log.debug("nss cmd: %s", format_cmd_list(cmd))
143               check_output(cmd, stderr=subprocess.STDOUT)
144               cmd = [
145                   '/usr/bin/certutil',
146 @@ -557,7 +557,7 @@
147                   '-f',
148                   '%s/%s' % (self._certdb, PWD_TXT),
149               ]
150 -             self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
151 +             self.log.debug("nss cmd: %s", format_cmd_list(cmd))
152               check_output(cmd, stderr=subprocess.STDOUT)
153   
154           if crt is not None:
155 @@ -572,7 +572,7 @@
156                   '-f',
157                   '%s/%s' % (self._certdb, PWD_TXT),
158               ]
159 -             self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
160 +             self.log.debug("nss cmd: %s", format_cmd_list(cmd))
161               check_output(cmd, stderr=subprocess.STDOUT)
162               cmd = [
163                   '/usr/bin/certutil',
164 @@ -581,7 +581,7 @@
165                   '-n', CERT_NAME,
166                   '-u', 'YCV'
167               ]
168 -             self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
169 +             self.log.debug("nss cmd: %s", format_cmd_list(cmd))
170               check_output(cmd, stderr=subprocess.STDOUT)
171   
172       def create_rsa_user(self, name, months=VALID):
173 @@ -624,10 +624,10 @@
174               '-f',
175               '%s/%s' % (self._certdb, PWD_TXT),
176           ]
177 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
178 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
179   
180           result = ensure_str(check_output(cmd, stderr=subprocess.STDOUT))
181 -         self.log.debug("nss output: %s" % result)
182 +         self.log.debug("nss output: %s", result)
183           # Now extract this into PEM files that we can use.
184           # pk12util -o user-william.p12 -d . -k pwdfile.txt -n user-william -W ''
185           cmd = [
186 @@ -638,7 +638,7 @@
187               '-n', '%s%s' % (USER_PREFIX, name),
188               '-W', '""'
189           ]
190 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
191 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
192           check_output(cmd, stderr=subprocess.STDOUT)
193           # openssl pkcs12 -in user-william.p12 -passin pass:'' -out file.pem -nocerts -nodes
194           # Extract the key
195 @@ -651,7 +651,7 @@
196               '-nocerts',
197               '-nodes'
198           ]
199 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
200 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
201           check_output(cmd, stderr=subprocess.STDOUT)
202           # Extract the cert
203           cmd = [
204 @@ -664,7 +664,7 @@
205               '-clcerts',
206               '-nodes'
207           ]
208 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
209 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
210           check_output(cmd, stderr=subprocess.STDOUT)
211           # Convert the cert for userCertificate attr
212           cmd = [
213 @@ -675,7 +675,7 @@
214               '-in', '%s/%s%s.crt' % (self._certdb, USER_PREFIX, name),
215               '-out', '%s/%s%s.der' % (self._certdb, USER_PREFIX, name),
216           ]
217 -         self.log.debug("nss cmd: %s" % format_cmd_list(cmd))
218 +         self.log.debug("nss cmd: %s", format_cmd_list(cmd))
219           check_output(cmd, stderr=subprocess.STDOUT)
220   
221           return subject
  1 @@ -113,10 +113,10 @@
  2                   raise KeyError
  3           except KeyError:
  4               if not repl_manager_pw:
  5 -                 self.log.warning("replica_createReplMgr: bind DN password " +
  6 +                 self.log.warning("replica_createReplMgr: bind DN password "
  7                                    "not specified")
  8               if not repl_manager_dn:
  9 -                 self.log.warning("replica_createReplMgr: bind DN not " +
 10 +                 self.log.warning("replica_createReplMgr: bind DN not "
 11                                    "specified")
 12               raise
 13   
 14 @@ -136,7 +136,7 @@
 15                        'passwordExpirationTime': '20381010000000Z'}
 16               self.conn.setupBindDN(repl_manager_dn, repl_manager_pw, attrs)
 17           except ldap.ALREADY_EXISTS:
 18 -             self.log.warn("User already exists (weird we just checked: %s " %
 19 +             self.log.warn("User already exists (weird we just checked: %s ",
 20                             repl_manager_dn)
 21   
 22       def list(self, suffix=None, replica_dn=None):
 23 @@ -215,8 +215,8 @@
 24               if not inProperties(prop, REPLICA_PROPNAME_TO_ATTRNAME):
 25                   raise ValueError("unknown property: %s" % prop)
 26               else:
 27 -                 self.log.debug("setProperties: %s:%s" %
 28 -                                (prop, properties[prop]))
 29 +                 self.log.debug("setProperties: %s:%s",
 30 +                                prop, properties[prop])
 31   
 32           # At least we need to have suffix/replica_dn/replica_entry
 33           if not suffix and not replica_dn and not replica_entry:
 34 @@ -334,12 +334,12 @@
 35               raise InvalidArgumentError("role missing")
 36   
 37           if not ReplicaLegacy._valid_role(role):
 38 -             self.log.fatal("enableReplication: replica role invalid (%s) " % role)
 39 +             self.log.fatal("enableReplication: replica role invalid (%s) ", role)
 40               raise ValueError("invalid role: %s" % role)
 41   
 42           # check the validity of 'rid'
 43           if not ReplicaLegacy._valid_rid(role, rid=rid):
 44 -             self.log.fatal("Replica.create: replica role is master but 'rid'" +
 45 +             self.log.fatal("Replica.create: replica role is master but 'rid'"
 46                              " is missing or invalid value")
 47               raise InvalidArgumentError("rid missing or invalid value")
 48   
 49 @@ -390,7 +390,7 @@
 50           dn_replica = ','.join((RDN_REPLICA, mtent.dn))
 51           try:
 52               entry = self.conn.getEntry(dn_replica, ldap.SCOPE_BASE)
 53 -             self.log.warn("Already setup replica for suffix %r" % nsuffix)
 54 +             self.log.warn("Already setup replica for suffix %r", nsuffix)
 55               self.conn.suffixes.setdefault(nsuffix, {})
 56               self.conn.replica.setProperties(replica_dn=dn_replica,
 57                                               properties=properties)
 58 @@ -434,13 +434,13 @@
 59                   try:
 60                       self.conn.delete_s(agmt.dn)
 61                   except ldap.LDAPError as e:
 62 -                     self.log.fatal('Failed to delete replica agreement (%s),' +
 63 -                                    ' error: %s' %
 64 -                                    (agmt.dn, str(e)))
 65 +                     self.log.fatal('Failed to delete replica agreement (%s),'
 66 +                                    ' error: %s',
 67 +                                    agmt.dn, e)
 68                       raise
 69           except ldap.LDAPError as e:
 70 -             self.log.fatal('Failed to search for replication agreements ' +
 71 -                            'under (%s), error: %s' % (dn_replica, str(e)))
 72 +             self.log.fatal('Failed to search for replication agreements '
 73 +                            'under (%s), error: %s', dn_replica, e)
 74               raise
 75   
 76       def disableReplication(self, suffix=None):
 77 @@ -481,8 +481,8 @@
 78           try:
 79               self.conn.delete_s(dn_replica)
 80           except ldap.LDAPError as e:
 81 -             self.log.fatal('Failed to delete replica configuration ' +
 82 -                            '(%s), error: %s' % (dn_replica, str(e)))
 83 +             self.log.fatal('Failed to delete replica configuration '
 84 +                            '(%s), error: %s', dn_replica, e)
 85               raise
 86   
 87       def enableReplication(self, suffix=None, role=None,
 88 @@ -493,7 +493,7 @@
 89               raise ValueError("suffix missing")
 90   
 91           if not role:
 92 -             self.log.fatal("enableReplication: replica role not specify " +
 93 +             self.log.fatal("enableReplication: replica role not specify "
 94                              "(ReplicaRole.*)")
 95               raise ValueError("role missing")
 96   
 97 @@ -502,10 +502,11 @@
 98           #
 99   
100           # First role and replicaID
101 -         if role != ReplicaRole.MASTER and \
102 -            role != ReplicaRole.HUB and \
103 -            role != ReplicaRole.CONSUMER:
104 -             self.log.fatal("enableReplication: replica role invalid (%s) " %
105 +         if (role != ReplicaRole.MASTER and
106 +             role != ReplicaRole.HUB and
107 +             role != ReplicaRole.CONSUMER
108 +         ):
109 +             self.log.fatal("enableReplication: replica role invalid (%s) ",
110                              role)
111               raise ValueError("invalid role: %s" % role)
112   
113 @@ -515,29 +516,29 @@
114                  (replicaId <= 0) or \
115                  (replicaId >= CONSUMER_REPLICAID):
116                   self.log.fatal("enableReplication: invalid replicaId (%s) "
117 -                                "for a RW replica" % replicaId)
118 +                                "for a RW replica", replicaId)
119                   raise ValueError("invalid replicaId %d (expected [1.."
120                                    "CONSUMER_REPLICAID]" % replicaId)
121           elif replicaId != CONSUMER_REPLICAID:
122               # check the replicaId is CONSUMER_REPLICAID
123               self.log.fatal("enableReplication: invalid replicaId (%s) for a "
124 -                            "Read replica (expected %d)" %
125 -                            (replicaId, CONSUMER_REPLICAID))
126 +                            "Read replica (expected %d)",
127 +                            replicaId, CONSUMER_REPLICAID)
128               raise ValueError("invalid replicaId: %d for HUB/CONSUMER "
129                                "replicaId is CONSUMER_REPLICAID" % replicaId)
130   
131           # Now check we have a suffix
132           entries_backend = self.conn.backend.list(suffix=suffix)
133           if not entries_backend:
134 -             self.log.fatal("enableReplication: unable to retrieve the " +
135 -                            "backend for %s" % suffix)
136 +             self.log.fatal("enableReplication: unable to retrieve the "
137 +                            "backend for %s", suffix)
138               raise ValueError("no backend for suffix %s" % suffix)
139   
140           ent = entries_backend[0]
141           if normalizeDN(suffix) != normalizeDN(ent.getValue('nsslapd-suffix')):
142               self.log.warning("enableReplication: suffix (%s) and backend "
143 -                              "suffix (%s) differs" %
144 -                              (suffix, entries_backend[0].nsslapd - suffix))
145 +                              "suffix (%s) differs",
146 +                              suffix, entries_backend[0].nsslapd - suffix)
147               pass
148   
149           # Now prepare the bindDN property
150 @@ -551,7 +552,7 @@
151                   # weird, internal error we do not retrieve the default
152                   # replication bind DN this replica will not be updatable
153                   # through replication until the binddn property will be set
154 -                 self.log.warning("enableReplication: binddn not provided and" +
155 +                 self.log.warning("enableReplication: binddn not provided and"
156                                    " default value unavailable")
157                   pass
158   
159 @@ -586,7 +587,7 @@
160               entry = self.conn.getEntry(
161                   agmtdn, ldap.SCOPE_BASE, "(objectclass=*)", attrlist)
162           except NoSuchEntryError:
163 -             self.log.exception("Error reading status from agreement %r" %
164 +             self.log.exception("Error reading status from agreement %r",
165                                  agmtdn)
166               hasError = 1
167           else:
168 @@ -639,7 +640,7 @@
169           """Initialize replication without waiting.
170               @param agmtdn - agreement dn
171           """
172 -         self.log.info("Starting async replication %s" % agmtdn)
173 +         self.log.info("Starting async replication %s", agmtdn)
174           mod = [(ldap.MOD_ADD, 'nsds5BeginReplicaRefresh', b'start')]
175           self.conn.modify_s(agmtdn, mod)
176   
177 @@ -666,8 +667,8 @@
178           if ents and (len(ents) > 0):
179               ent = ents[0]
180           elif tryrepl:
181 -             self.log.warn("Could not get RUV from %r entry -" +
182 -                           " trying cn=replica" % suffix)
183 +             self.log.warn("Could not get RUV from %r entry -"
184 +                           " trying cn=replica", suffix)
185               ensuffix = escapeDNValue(normalizeDN(suffix))
186               dn = ','.join(("cn=replica", "cn=%s" % ensuffix, DN_MAPPING_TREE))
187               ents = self.conn.search_s(dn, ldap.SCOPE_BASE, "objectclass=*",
188 @@ -675,7 +676,7 @@
189   
190           if ents and (len(ents) > 0):
191               ent = ents[0]
192 -             self.log.debug("RUV entry is %r" % ent)
193 +             self.log.debug("RUV entry is %r", ent)
194               return RUV(ent)
195   
196           raise NoSuchEntryError("RUV not found: suffix: %r" % suffix)
  1 @@ -262,7 +262,7 @@
  2           dn = entry.dn
  3           while not done:
  4               entry = self.conn.getEntry(dn, attrlist=attrlist)
  5 -             self.log.debug("task entry %r" % entry)
  6 +             self.log.debug("task entry %r", entry)
  7   
  8               if entry.nsTaskExitCode:
  9                   exitCode = int(entry.nsTaskExitCode)
 10 @@ -331,11 +331,11 @@
 11               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
 12   
 13           if exitCode:
 14 -             self.log.error("Error: import task %s for file %s exited with %d" %
 15 -                            (cn, input_file, exitCode))
 16 +             self.log.error("Error: import task %s for file %s exited with %d",
 17 +                            cn, input_file, exitCode)
 18           else:
 19 -             self.log.info("Import task %s for file %s completed successfully" %
 20 -                           (cn, input_file))
 21 +             self.log.info("Import task %s for file %s completed successfully",
 22 +                           cn, input_file)
 23           self.dn = dn
 24           self.entry = entry
 25           return exitCode
 26 @@ -400,11 +400,11 @@
 27               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
 28   
 29           if exitCode:
 30 -             self.log.error("Error: export task %s for file %s exited with %d" %
 31 -                            (cn, output_file, exitCode))
 32 +             self.log.error("Error: export task %s for file %s exited with %d",
 33 +                            cn, output_file, exitCode)
 34           else:
 35 -             self.log.info("Export task %s for file %s completed successfully" %
 36 -                           (cn, output_file))
 37 +             self.log.info("Export task %s for file %s completed successfully",
 38 +                           cn, output_file)
 39   
 40           self.dn = dn
 41           self.entry = entry
 42 @@ -444,7 +444,7 @@
 43           try:
 44               self.conn.add_s(entry)
 45           except ldap.ALREADY_EXISTS:
 46 -             self.log.error("Fail to add the backup task (%s)" % dn)
 47 +             self.log.error("Fail to add the backup task (%s)", dn)
 48               return -1
 49   
 50           exitCode = 0
 51 @@ -452,10 +452,10 @@
 52               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
 53   
 54           if exitCode:
 55 -             self.log.error("Error: backup task %s exited with %d" %
 56 -                            (cn, exitCode))
 57 +             self.log.error("Error: backup task %s exited with %d",
 58 +                            cn, exitCode)
 59           else:
 60 -             self.log.info("Backup task %s completed successfully" % (cn))
 61 +             self.log.info("Backup task %s completed successfully", cn)
 62   
 63           self.dn = dn
 64           self.entry = entry
 65 @@ -506,7 +506,7 @@
 66           try:
 67               self.conn.add_s(entry)
 68           except ldap.ALREADY_EXISTS:
 69 -             self.log.error("Fail to add the backup task (%s)" % dn)
 70 +             self.log.error("Fail to add the backup task (%s)", dn)
 71               return -1
 72   
 73           exitCode = 0
 74 @@ -514,10 +514,10 @@
 75               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
 76   
 77           if exitCode:
 78 -             self.log.error("Error: restore task %s exited with %d" %
 79 -                            (cn, exitCode))
 80 +             self.log.error("Error: restore task %s exited with %d",
 81 +                            cn, exitCode)
 82           else:
 83 -             self.log.info("Restore task %s completed successfully" % (cn))
 84 +             self.log.info("Restore task %s completed successfully", cn)
 85   
 86           self.dn = dn
 87           self.entry = entry
 88 @@ -605,7 +605,7 @@
 89           try:
 90               self.conn.add_s(entry)
 91           except ldap.ALREADY_EXISTS:
 92 -             self.log.error("Fail to add the index task for %s" % attrname)
 93 +             self.log.error("Fail to add the index task for %s", attrname)
 94               return -1
 95   
 96           exitCode = 0
 97 @@ -613,10 +613,10 @@
 98               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
 99   
100           if exitCode:
101 -             self.log.error("Error: index task %s exited with %d" %
102 -                            (cn, exitCode))
103 +             self.log.error("Error: index task %s exited with %d",
104 +                            cn, exitCode)
105           else:
106 -             self.log.info("Index task %s completed successfully" % (cn))
107 +             self.log.info("Index task %s completed successfully", cn)
108   
109           self.dn = dn
110           self.entry = entry
111 @@ -692,12 +692,12 @@
112   
113           if exitCode:
114               self.log.error(
115 -                 "Error: fixupMemberOf task %s for basedn %s exited with %d" %
116 -                 (cn, suffix, exitCode))
117 +                 "Error: fixupMemberOf task %s for basedn %s exited with %d",
118 +                 cn, suffix, exitCode)
119           else:
120               self.log.info(
121 -                 "fixupMemberOf task %s for basedn %s completed successfully" %
122 -                 (cn, suffix))
123 +                 "fixupMemberOf task %s for basedn %s completed successfully",
124 +                 cn, suffix)
125   
126           self.dn = dn
127           self.entry = entry
128 @@ -751,12 +751,14 @@
129   
130           if exitCode:
131               self.log.error(
132 -                 "Error: tombstone fixup task %s for backend %s exited with %d"
133 -                 % (cn, bename, exitCode))
134 +                 "Error: tombstone fixup task %s for backend %s exited "
135 +                 "with %d",
136 +                 cn, bename, exitCode)
137           else:
138               self.log.info(
139 -                 "tombstone fixup task %s for backend %s completed successfully"
140 -                 % (cn, bename))
141 +                 "tombstone fixup task %s for backend %s completed "
142 +                 "successfully",
143 +                 cn, bename)
144   
145           self.dn = dn
146           self.entry = entry
147 @@ -799,12 +801,12 @@
148   
149           if exitCode:
150               self.log.error(
151 -                 "Error: Automember Rebuild Membership task (%s) exited with %d"
152 -                 % (cn, exitCode))
153 +                 "Error: Automember Rebuild Membership task (%s) exited "
154 +                 "with %d", cn, exitCode)
155           else:
156               self.log.info(
157 -                 "Automember Rebuild Membership task(%s) completed successfully"
158 -                 % (cn))
159 +                 "Automember Rebuild Membership task(%s) completed"
160 +                 "successfully", cn)
161   
162           self.dn = dn
163           self.entry = entry
164 @@ -852,12 +854,12 @@
165   
166           if exitCode:
167               self.log.error(
168 -                 "Error: Automember Export Updates task (%s) exited with %d" %
169 -                 (cn, exitCode))
170 +                 "Error: Automember Export Updates task (%s) exited with %d",
171 +                 cn, exitCode)
172           else:
173               self.log.info(
174 -                 "Automember Export Updates task (%s) completed successfully" %
175 -                 (cn))
176 +                 "Automember Export Updates task (%s) completed successfully",
177 +                 cn)
178   
179           self.dn = dn
180           self.entry = entry
181 @@ -900,12 +902,11 @@
182   
183           if exitCode:
184               self.log.error(
185 -                 "Error: Automember Map Updates task (%s) exited with %d" %
186 -                 (cn, exitCode))
187 +                 "Error: Automember Map Updates task (%s) exited with %d",
188 +                 cn, exitCode)
189           else:
190               self.log.info(
191 -                 "Automember Map Updates task (%s) completed successfully" %
192 -                 (cn))
193 +                 "Automember Map Updates task (%s) completed successfully", cn)
194   
195           self.dn = dn
196           self.entry = entry
197 @@ -943,12 +944,11 @@
198   
199           if exitCode:
200               self.log.error(
201 -                 "Error: Fixup Linked Attributes task (%s) exited with %d" %
202 -                 (cn, exitCode))
203 +                 "Error: Fixup Linked Attributes task (%s) exited with %d",
204 +                 cn, exitCode)
205           else:
206               self.log.info(
207 -                 "Fixup Linked Attributes task (%s) completed successfully" %
208 -                 (cn))
209 +                 "Fixup Linked Attributes task (%s) completed successfully", cn)
210   
211           self.dn = dn
212           self.entry = entry
213 @@ -984,11 +984,10 @@
214               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
215   
216           if exitCode:
217 -             self.log.error("Error: Schema Reload task (%s) exited with %d" %
218 -                            (cn, exitCode))
219 +             self.log.error("Error: Schema Reload task (%s) exited with %d",
220 +                            cn, exitCode)
221           else:
222 -             self.log.info("Schema Reload task (%s) completed successfully" %
223 -                           (cn))
224 +             self.log.info("Schema Reload task (%s) completed successfully", cn)
225   
226           self.dn = dn
227           self.entry = entry
228 @@ -1028,11 +1027,11 @@
229   
230           if exitCode:
231               self.log.error(
232 -                 "fixupWinsyncMembers 'memberuid task' (%s) exited with %d" %
233 -                 (cn, exitCode))
234 +                 "fixupWinsyncMembers 'memberuid task' (%s) exited with %d",
235 +                 cn, exitCode)
236           else:
237               self.log.info(
238 -                 "'memberuid task' (%s) completed successfully" % (cn))
239 +                 "'memberuid task' (%s) completed successfully", cn)
240   
241           self.dn = dn
242           self.entry = entry
243 @@ -1071,11 +1070,11 @@
244               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
245   
246           if exitCode:
247 -             self.log.error("Error: Syntax Validate (%s) exited with %d" %
248 -                            (cn, exitCode))
249 +             self.log.error("Error: Syntax Validate (%s) exited with %d",
250 +                            cn, exitCode)
251           else:
252 -             self.log.info("Syntax Validate task (%s) completed successfully" %
253 -                           (cn))
254 +             self.log.info("Syntax Validate task (%s) completed successfully",
255 +                           cn)
256   
257           self.dn = dn
258           self.entry = entry
259 @@ -1120,12 +1119,11 @@
260   
261           if exitCode:
262               self.log.error(
263 -                 "Error: USN tombstone cleanup task (%s) exited with %d" %
264 -                 (cn, exitCode))
265 +                 "Error: USN tombstone cleanup task (%s) exited with %d",
266 +                 cn, exitCode)
267           else:
268               self.log.info(
269 -                 "USN tombstone cleanup task (%s) completed successfully" %
270 -                 (cn))
271 +                 "USN tombstone cleanup task (%s) completed successfully", cn)
272   
273           self.dn = dn
274           self.entry = entry
275 @@ -1168,11 +1166,11 @@
276               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
277   
278           if exitCode:
279 -             self.log.error("Error: Sysconfig Reload task (%s) exited with %d" %
280 -                            (cn, exitCode))
281 +             self.log.error("Error: Sysconfig Reload task (%s) exited with %d",
282 +                            cn, exitCode)
283           else:
284 -             self.log.info("Sysconfig Reload task (%s) completed successfully" %
285 -                           (cn))
286 +             self.log.info("Sysconfig Reload task (%s) completed successfully",
287 +                           cn)
288   
289           self.dn = dn
290           self.entry = entry
291 @@ -1217,11 +1215,10 @@
292               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
293   
294           if exitCode:
295 -             self.log.error("Error: cleanAllRUV task (%s) exited with %d" %
296 -                            (cn, exitCode))
297 +             self.log.error("Error: cleanAllRUV task (%s) exited with %d",
298 +                            cn, exitCode)
299           else:
300 -             self.log.info("cleanAllRUV task (%s) completed successfully" %
301 -                           (cn))
302 +             self.log.info("cleanAllRUV task (%s) completed successfully", cn)
303   
304           self.dn = dn
305           self.entry = entry
306 @@ -1271,12 +1268,11 @@
307   
308           if exitCode:
309               self.log.error(
310 -                 "Error: Abort cleanAllRUV task (%s) exited with %d" %
311 -                 (cn, exitCode))
312 +                 "Error: Abort cleanAllRUV task (%s) exited with %d",
313 +                 cn, exitCode)
314           else:
315               self.log.info(
316 -                 "Abort cleanAllRUV task (%s) completed successfully" %
317 -                 (cn))
318 +                 "Abort cleanAllRUV task (%s) completed successfully", cn)
319   
320           self.dn = dn
321           self.entry = entry
322 @@ -1322,10 +1318,10 @@
323               (done, exitCode) = self.conn.tasks.checkTask(entry, True)
324   
325           if exitCode:
326 -             self.log.error("Error: upgradedb task (%s) exited with %d" %
327 -                            (cn, exitCode))
328 +             self.log.error("Error: upgradedb task (%s) exited with %d",
329 +                            cn, exitCode)
330           else:
331 -             self.log.info("Upgradedb task (%s) completed successfully" % (cn))
332 +             self.log.info("Upgradedb task (%s) completed successfully", cn)
333   
334           self.dn = dn
335           self.entry = entry