|
43 |
from ucsschool.importer.configuration import Configuration |
43 |
from ucsschool.importer.configuration import Configuration |
44 |
from ucsschool.importer.utils.logging import get_logger |
44 |
from ucsschool.importer.utils.logging import get_logger |
45 |
from ucsschool.importer.utils.ldap_connection import get_admin_connection |
45 |
from ucsschool.importer.utils.ldap_connection import get_admin_connection |
|
|
46 |
from memory_profiler import profile, LogFile |
46 |
|
47 |
|
47 |
|
48 |
|
48 |
class UserImport(object): |
49 |
class UserImport(object): |
|
61 |
self.connection, self.position = get_admin_connection() |
62 |
self.connection, self.position = get_admin_connection() |
62 |
self.factory = Factory() |
63 |
self.factory = Factory() |
63 |
self.reader = self.factory.make_reader() |
64 |
self.reader = self.factory.make_reader() |
|
|
65 |
sys.stdout = LogFile(self.logger.name, reportIncrementFlag=False) |
64 |
|
66 |
|
|
|
67 |
@profile(precision=3) |
65 |
def read_input(self): |
68 |
def read_input(self): |
66 |
""" |
69 |
""" |
67 |
Read users from input data. |
70 |
Read users from input data. |
|
86 |
self.logger.info("------ Read %d users from input data. ------", len(self.imported_users)) |
89 |
self.logger.info("------ Read %d users from input data. ------", len(self.imported_users)) |
87 |
return self.imported_users |
90 |
return self.imported_users |
88 |
|
91 |
|
|
|
92 |
@profile(precision=3) |
89 |
def create_and_modify_users(self, imported_users=None): |
93 |
def create_and_modify_users(self, imported_users=None): |
90 |
""" |
94 |
""" |
91 |
Create and modify users. |
95 |
Create and modify users. |
|
98 |
:return tuple: (self.errors, self.added_users, self.modified_users) |
102 |
:return tuple: (self.errors, self.added_users, self.modified_users) |
99 |
""" |
103 |
""" |
100 |
self.logger.info("------ Creating / modifying users... ------") |
104 |
self.logger.info("------ Creating / modifying users... ------") |
101 |
for imported_user in imported_users: |
105 |
usernum = 0 |
|
|
106 |
total = len(imported_users) |
107 |
while imported_users: |
108 |
imported_user = imported_users.pop(0) |
109 |
usernum += 1 |
102 |
if imported_user.action == "D": |
110 |
if imported_user.action == "D": |
103 |
continue |
111 |
continue |
104 |
try: |
112 |
try: |
105 |
self.logger.debug("Creating / modifying user %s...", imported_user) |
113 |
self.logger.debug("Creating / modifying user %d/%d %s...", usernum, total, imported_user) |
106 |
user = self.determine_add_modify_action(imported_user) |
114 |
user = self.determine_add_modify_action(imported_user) |
107 |
cls_name = user.__class__.__name__ |
115 |
cls_name = user.__class__.__name__ |
108 |
|
116 |
|
|
146 |
user.record_uid, exc), validation_error=exc, import_user=user), sys.exc_info()[2] |
154 |
user.record_uid, exc), validation_error=exc, import_user=user), sys.exc_info()[2] |
147 |
|
155 |
|
148 |
if success: |
156 |
if success: |
149 |
self.logger.info("Success %s %s (source_uid:%s record_uid: %s).", action_str.lower(), user, |
157 |
self.logger.info("Success %s %d/%d %s (source_uid:%s record_uid: %s).", action_str.lower(), usernum, total, user, user.source_uid, user.record_uid) |
150 |
user.source_uid, user.record_uid) |
158 |
store.append(user.to_dict_all()) |
151 |
store.append(user) |
|
|
152 |
else: |
159 |
else: |
153 |
raise err("Error {} {} (source_uid:{} record_uid: {}), does probably {}exist.".format( |
160 |
raise err("Error {} {}/{} {} (source_uid:{} record_uid: {}), does probably {}exist.".format( |
154 |
action_str.lower(), user, user.source_uid, user.record_uid, |
161 |
action_str.lower(), usernum, len(imported_users), user, user.source_uid, user.record_uid, |
155 |
"not " if user.action == "M" else "already "), entry=user.entry_count, import_user=user) |
162 |
"not " if user.action == "M" else "already "), entry=user.entry_count, import_user=user) |
156 |
|
|
|
157 |
except (CreationError, ModificationError) as exc: |
163 |
except (CreationError, ModificationError) as exc: |
158 |
self.logger.error("Entry #%d: %s", exc.entry, exc) # traceback useless |
164 |
self.logger.error("Entry #%d: %s", exc.entry, exc) # traceback useless |
159 |
self._add_error(exc) |
165 |
self._add_error(exc) |
|
197 |
user.action = "A" |
203 |
user.action = "A" |
198 |
return user |
204 |
return user |
199 |
|
205 |
|
|
|
206 |
@profile(precision=3) |
200 |
def detect_users_to_delete(self): |
207 |
def detect_users_to_delete(self): |
201 |
""" |
208 |
""" |
202 |
Find difference between source database and UCS user database. |
209 |
Find difference between source database and UCS user database. |
|
205 |
""" |
212 |
""" |
206 |
self.logger.info("------ Detecting which users to delete... ------") |
213 |
self.logger.info("------ Detecting which users to delete... ------") |
207 |
users_to_delete = list() |
214 |
users_to_delete = list() |
208 |
a_user = self.factory.make_import_user([]) |
|
|
209 |
|
215 |
|
210 |
if self.config["no_delete"]: |
216 |
if self.config["no_delete"]: |
211 |
self.logger.info("------ Looking only for users with action='D' (no_delete=%r) ------", |
217 |
self.logger.info("------ Looking only for users with action='D' (no_delete=%r) ------", |
|
213 |
for user in self.imported_users: |
219 |
for user in self.imported_users: |
214 |
if user.action == "D": |
220 |
if user.action == "D": |
215 |
try: |
221 |
try: |
216 |
ldap_user = a_user.get_by_import_id(self.connection, user.source_uid, user.record_uid) |
222 |
users_to_delete.append((user.source_uid, user.record_uid)) |
217 |
ldap_user.update(user) # need user.input_data for hooks |
|
|
218 |
users_to_delete.append(ldap_user) |
219 |
except noObject: |
223 |
except noObject: |
220 |
msg = "User to delete not found in LDAP: {}.".format(user) |
224 |
msg = "User to delete not found in LDAP: {}.".format(user) |
221 |
self.logger.error(msg) |
225 |
self.logger.error(msg) |
|
235 |
ucs_ldap_users = self.connection.search(filter_s, attr=attr) |
239 |
ucs_ldap_users = self.connection.search(filter_s, attr=attr) |
236 |
ucs_user_ids = set([(lu[1]["ucsschoolSourceUID"][0], lu[1]["ucsschoolRecordUID"][0]) for lu in ucs_ldap_users]) |
240 |
ucs_user_ids = set([(lu[1]["ucsschoolSourceUID"][0], lu[1]["ucsschoolRecordUID"][0]) for lu in ucs_ldap_users]) |
237 |
|
241 |
|
238 |
# collect ucschool objects for those users to delete in imported_users |
242 |
users_to_delete = list(ucs_user_ids - imported_user_ids) |
239 |
for ucs_id_not_in_import in (ucs_user_ids - imported_user_ids): |
|
|
240 |
try: |
241 |
ldap_user = a_user.get_by_import_id(self.connection, ucs_id_not_in_import[0], ucs_id_not_in_import[1]) |
242 |
ldap_user.action = "D" # mark for logging/csv-output purposes |
243 |
users_to_delete.append(ldap_user) |
244 |
except noObject as exc: |
245 |
self.logger.error("Cannot delete non existing user with source_uid=%r, record_uid=%r: %s", |
246 |
ucs_id_not_in_import[0], ucs_id_not_in_import[1], exc) |
247 |
|
248 |
self.logger.debug("users_to_delete=%r", users_to_delete) |
243 |
self.logger.debug("users_to_delete=%r", users_to_delete) |
249 |
return users_to_delete |
244 |
return users_to_delete |
250 |
|
245 |
|
|
|
246 |
@profile(precision=3) |
251 |
def delete_users(self, users=None): |
247 |
def delete_users(self, users=None): |
252 |
""" |
248 |
""" |
253 |
Delete users. |
249 |
Delete users. |
|
261 |
:return: tuple: (self.errors, self.deleted_users) |
257 |
:return: tuple: (self.errors, self.deleted_users) |
262 |
""" |
258 |
""" |
263 |
self.logger.info("------ Deleting %d users... ------", len(users)) |
259 |
self.logger.info("------ Deleting %d users... ------", len(users)) |
264 |
for user in users: |
260 |
a_user = self.factory.make_import_user([]) |
|
|
261 |
for num, ucs_id_not_in_import in enumerate(users): |
265 |
try: |
262 |
try: |
|
|
263 |
user = a_user.get_by_import_id(self.connection, ucs_id_not_in_import[0], ucs_id_not_in_import[1]) |
264 |
user.action = "D" # mark for logging/csv-output purposes |
265 |
except noObject as exc: |
266 |
self.logger.error("Cannot delete non existing user with source_uid=%r, record_uid=%r: %s", |
267 |
ucs_id_not_in_import[0], ucs_id_not_in_import[1], exc) |
268 |
continue |
269 |
try: |
266 |
success = self.do_delete(user) |
270 |
success = self.do_delete(user) |
267 |
if success: |
271 |
if success: |
268 |
self.logger.info("Success deleting user %r (source_uid:%s record_uid: %s).", user.name, |
272 |
self.logger.info("Success deleting %d/%d %r (source_uid:%s record_uid: %s).", num, len(users), |
269 |
user.source_uid, user.record_uid) |
273 |
user.name, user.source_uid, user.record_uid) |
270 |
else: |
274 |
else: |
271 |
raise DeletionError("Error deleting user '{}' (source_uid:{} record_uid: {}), has probably already " |
275 |
raise DeletionError("Error deleting user '{}' (source_uid:{} record_uid: {}), has probably already " |
272 |
"been deleted.".format(user.name, user.source_uid, user.record_uid), entry=user.entry_count, |
276 |
"been deleted.".format(user.name, user.source_uid, user.record_uid), entry=user.entry_count, |
273 |
import_user=user) |
277 |
import_user=user) |
274 |
self.deleted_users[user.__class__.__name__].append(user) |
278 |
self.deleted_users[user.__class__.__name__].append(user.to_dict_all()) |
275 |
except UcsSchoolImportError as exc: |
279 |
except UcsSchoolImportError as exc: |
276 |
self.logger.exception("Error in entry #%d: %s", exc.entry, exc) |
280 |
self.logger.exception("Error in entry #%d: %s", exc.entry, exc) |
277 |
self._add_error(exc) |
281 |
self._add_error(exc) |
|
352 |
raise UnknownDeleteSetting("Don't know what to do with user_deletion=%r and expiration=%r.".format( |
356 |
raise UnknownDeleteSetting("Don't know what to do with user_deletion=%r and expiration=%r.".format( |
353 |
self.config["user_deletion"]["delete"], self.config["user_deletion"]["expiration"]), |
357 |
self.config["user_deletion"]["delete"], self.config["user_deletion"]["expiration"]), |
354 |
entry=user.entry_count, import_user=user) |
358 |
entry=user.entry_count, import_user=user) |
|
|
359 |
user.invalidate_all_caches() |
355 |
return success |
360 |
return success |
356 |
|
361 |
|
357 |
def log_stats(self): |
362 |
def log_stats(self): |
|
368 |
for cls_name in sorted(cls_names): |
373 |
for cls_name in sorted(cls_names): |
369 |
self.logger.info("Created %s: %d", cls_name, len(self.added_users.get(cls_name, []))) |
374 |
self.logger.info("Created %s: %d", cls_name, len(self.added_users.get(cls_name, []))) |
370 |
for i in range(0, len(self.added_users[cls_name]), columns): |
375 |
for i in range(0, len(self.added_users[cls_name]), columns): |
371 |
self.logger.info(" %s", [iu.name for iu in self.added_users[cls_name][i:i+columns]]) |
376 |
self.logger.info(" %s", [iu["name"] for iu in self.added_users[cls_name][i:i+columns]]) |
372 |
self.logger.info("Modified %s: %d", cls_name, len(self.modified_users.get(cls_name, []))) |
377 |
self.logger.info("Modified %s: %d", cls_name, len(self.modified_users.get(cls_name, []))) |
373 |
for i in range(0, len(self.modified_users[cls_name]), columns): |
378 |
for i in range(0, len(self.modified_users[cls_name]), columns): |
374 |
self.logger.info(" %s", [iu.name for iu in self.modified_users[cls_name][i:i+columns]]) |
379 |
self.logger.info(" %s", [iu["name"] for iu in self.modified_users[cls_name][i:i+columns]]) |
375 |
self.logger.info("Deleted %s: %d", cls_name, len(self.deleted_users.get(cls_name, []))) |
380 |
self.logger.info("Deleted %s: %d", cls_name, len(self.deleted_users.get(cls_name, []))) |
376 |
for i in range(0, len(self.deleted_users[cls_name]), columns): |
381 |
for i in range(0, len(self.deleted_users[cls_name]), columns): |
377 |
self.logger.info(" %s", [iu.name for iu in self.deleted_users[cls_name][i:i+columns]]) |
382 |
self.logger.info(" %s", [iu["name"] for iu in self.deleted_users[cls_name][i:i+columns]]) |
378 |
self.logger.info("Errors: %d", len(self.errors)) |
383 |
self.logger.info("Errors: %d", len(self.errors)) |
379 |
if self.errors: |
384 |
if self.errors: |
380 |
self.logger.info("Entry #: Error description") |
385 |
self.logger.info("Entry #: Error description") |