Bug 42942 - Missing information in case of an exception (ImportUser.udm_attributes)
Missing information in case of an exception (ImportUser.udm_attributes)
Status: CLOSED FIXED
Product: UCS@school
Classification: Unclassified
Component: Import scripts
UCS@school 4.1 R2
Other Linux
: P5 normal (vote)
: UCS@school 4.1 R2 vXXX
Assigned To: Sönke Schwardt-Krummrich
Daniel Tröder
: interim-3
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2016-11-14 10:51 CET by Sönke Schwardt-Krummrich
Modified: 2016-12-12 13:10 CET (History)
1 user (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 2: Improvement: Would be a product improvement
Who will be affected by this bug?: 2: Will only affect a few installed domains
How will those affected feel about the bug?: 1: Nuisance – not a big deal but noticeable
User Pain: 0.023
Enterprise Customer affected?:
School Customer affected?: Yes
ISV affected?:
Waiting Support:
Ticket number:
Bug group (optional): Error handling, External feedback, Troubleshooting
Max CVSS v3 score:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Sönke Schwardt-Krummrich univentionstaff 2016-11-14 10:51:32 CET
Happened due to a customer pyhook. There is no information which property did cause the traceback.

2016-11-12 20:54:31 ERROR cmdline.main:136  Outer Exception catcher: TypeError('expected string or buffer',)
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/frontend/cmdline.py", line 116, in main
    self.do_import()
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/legacy/legacy_user_import_cmdline.py", line 62, in do_import
    importer.import_users()
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/mass_import/mass_import.py", line 98, in import_users
    user_import.create_and_modify_users(imported_users)
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/mass_import/user_import.py", line 131, in create_and_modify_users
    success = user.create(lo=self.connection)
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/models/import_user.py", line 150, in create
    return super(ImportUser, self).create(lo, validate)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 420, in create
    success = self.create_without_hooks(lo, validate)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 446, in create_without_hooks
    self.do_create(udm_obj, lo)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py", line 252, in do_create
    success = super(User, self).do_create(udm_obj, lo)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 462, in do_create
    self._alter_udm_obj(udm_obj)
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/models/import_user.py", line 192, in _alter_udm_obj
    udm_obj[property_] = value
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 253, in __setitem__
    p = s.parse(value)
  File "/usr/lib/pymodules/python2.7/univention/admin/syntax.py", line 319, in parse
    if not text or not self.regex or self.regex.match(text) is not None:
TypeError: expected string or buffer
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/frontend/cmdline.py", line 116, in main
    self.do_import()
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/legacy/legacy_user_import_cmdline.py", line 62, in do_import
    importer.import_users()
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/mass_import/mass_import.py", line 98, in import_users
    user_import.create_and_modify_users(imported_users)
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/mass_import/user_import.py", line 131, in create_and_modify_users
    success = user.create(lo=self.connection)
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/models/import_user.py", line 150, in create
    return super(ImportUser, self).create(lo, validate)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 420, in create
    success = self.create_without_hooks(lo, validate)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 446, in create_without_hooks
    self.do_create(udm_obj, lo)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py", line 252, in do_create
    success = super(User, self).do_create(udm_obj, lo)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 462, in do_create
    self._alter_udm_obj(udm_obj)
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/models/import_user.py", line 192, in _alter_udm_obj
    udm_obj[property_] = value
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 253, in __setitem__
    p = s.parse(value)
  File "/usr/lib/pymodules/python2.7/univention/admin/syntax.py", line 319, in parse
    if not text or not self.regex or self.regex.match(text) is not None:
TypeError: expected string or buffer
Comment 1 Sönke Schwardt-Krummrich univentionstaff 2016-11-14 11:33:17 CET
Added additional log output in case of an exception and reraise the caught exception.

Package: ucs-school-import
Version: 14.0.16-35.327.201611141130
Branch: ucs_4.1-0
Scope: ucs-school-4.1r2

ucs-school-import.yaml:
r74379 | Bug #42942: added additional log output in case of an exception
r74386 | Bug #42942: updated advisory

ucs-school-import (14.0.16-35):
r74379 | Bug #42942: added additional log output in case of an exception
Comment 2 Daniel Tröder univentionstaff 2016-11-14 12:31:01 CET
Please fix (additionally) at problem origin:

Index: ucs-school-lib/python/models/attributes.py
===================================================================
--- ucs-school-lib/python/models/attributes.py  (Revision 74388)
+++ ucs-school-lib/python/models/attributes.py  (Arbeitskopie)
@@ -69,7 +69,7 @@
                        for val in values:
                                try:
                                        syntax.parse(val)
-                               except valueError as e:
+                               except (valueError, TypeError) as e:
                                        raise ValueError(str(e))
 
        def validate(self, value):


This will create to the desired ucsschool.lib.models.attributes.ValidationError.
Comment 3 Florian Best univentionstaff 2016-11-14 12:49:08 CET
Which concrete property is affected here?
We should not catch TypeError here but we should fix that specific syntax class in UCS. Otherwise we don't recognize such errors anymore as they are shown as validation-error instead of the-syntax-class-is-broken.

The hook script should not set the value to None.
Comment 4 Daniel Tröder univentionstaff 2016-11-14 12:56:41 CET
The traceback can be provoked like this:

Student(school="SchuleEinz", name="randomname", firstname="randomname", lastname="randomname", birthday=dict(a="A")).create(lo)
Comment 5 Daniel Tröder univentionstaff 2016-11-14 13:00:12 CET
syntax.py in parse(self, text) could check isinstance(text, basestring) or better catch the TypeError itself
Comment 6 Florian Best univentionstaff 2016-11-14 13:13:37 CET
Why is the pyhook giving a dict? That should be fixed.
The syntax class should raise a uexceptions.valueError in this case.
Comment 7 Daniel Tröder univentionstaff 2016-11-14 14:13:22 CET
(In reply to Florian Best from comment #6)
> Why is the pyhook giving a dict? That should be fixed.
Nobody knows what happend in the traceback of the OP. That's why additional log output (r74379) was added.
I just tried to find out where this comes from, and provided an example how to recreate the same traceback.
Comment 8 Sönke Schwardt-Krummrich univentionstaff 2016-11-15 17:47:32 CET
(In reply to Florian Best from comment #3)
> Which concrete property is affected here?

the pyhook used the following faulty line:

 user.udm_properties['mailHomeServer'] = [mail_home_server]

So a list has been assigned to property "mailHomeServer" but this is not allowed.
Correct is a single value/string:

 user.udm_properties['mailHomeServer'] = mail_home_server

> We should not catch TypeError here but we should fix that specific syntax
> class in UCS. Otherwise we don't recognize such errors anymore as they are
> shown as validation-error instead of the-syntax-class-is-broken.

I also think that we should fix the UDM syntax → the syntax should raise a ValueError exception.

> The hook script should not set the value to None.

This was not the case.

(In reply to Florian Best from comment #6)
> Why is the pyhook giving a dict? That should be fixed.

That's what this bug is for. Help fixing the pyhook. In this customer scenario, 2 pyhooks were present that alter a lot of properties.

> The syntax class should raise a uexceptions.valueError in this case.

ACK

(In reply to Daniel Tröder from comment #7)
> (In reply to Florian Best from comment #6)
> > Why is the pyhook giving a dict? That should be fixed.
> Nobody knows what happend in the traceback of the OP. That's why additional
> log output (r74379) was added.
> I just tried to find out where this comes from, and provided an example how
> to recreate the same traceback.

Yes, this was the reason. To make debugging for us and customers/partners easier. At first, I had no idea which property caused the original traceback.


@Daniel:
Currently I don't like the suggested patch of comment 2 because it hides the exact traceback location. The original traceback in syntax.py is caught and a new exception is thrown. So the original strack trace is lost. In this case I known the property causing problems, but not where (and depending on the exception) not why. I would leave it as it is for now.
If there are any objections: please reopen.
Comment 9 Daniel Tröder univentionstaff 2016-11-16 14:55:23 CET
(In reply to Sönke Schwardt-Krummrich from comment #8)
> @Daniel:
> Currently I don't like the suggested patch of comment 2 because it hides the
> exact traceback location. The original traceback in syntax.py is caught and
> a new exception is thrown. So the original strack trace is lost. In this
> case I known the property causing problems, but not where (and depending on
> the exception) not why. I would leave it as it is for now.
> If there are any objections: please reopen.
I concur, that the traceback should be shown completely.

But the Exception still needs to be changed to a non-fatal error. At this code location the errors should be considered user specific and not abort a complete import run.

You can either use logger.exception("UDM property %r could not...", ..) to print the complete traceback to the logfile or/and
raise (
    UcsSchoolImportError,
    UcsSchoolImportError(
        "UDM property '{}' could not...".format(..),
	import_user=user),
    sys.exc_info()[2]
)
Comment 10 Sönke Schwardt-Krummrich univentionstaff 2016-12-07 14:10:03 CET
Revamped patch:
- print stacktrace of exception into log
- raise UDMError instead of reraising catched exception
  → exception is no longer fatal

ucs-school-import (14.0.16-40):
r75069 | Bug #42942: updated log output in case of an exception

Package: ucs-school-import
Version: 14.0.16-40.331.201612071408
Branch: ucs_4.1-0
Scope: ucs-school-4.1r2

2016-06-06 06:48:20 DEBUG base.cache:209  Initializing ('Group', ('name', 'schueler-gsnord'), ('school', 'gsnord'))
2016-06-06 06:48:20 DEBUG base.get_only_udm_obj:862  Getting SchoolClass UDM object by filter: name=gsnord-6zwo
2016-06-06 06:48:20 DEBUG base.get_only_udm_obj:862  Getting Group UDM object by filter: name=schueler-gsnord
2016-06-06 06:48:20 ERROR import_user._alter_udm_obj:198  Unexpected exception caught: UDM property 'mailHomeServer' could not be set for user 'anton303' in import line 1: exception: expected string or buffer
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/models/import_user.py", line 192, in _alter_udm_obj
    udm_obj[property_] = value
  File "/usr/lib/pymodules/python2.7/univention/admin/handlers/__init__.py", line 253, in __setitem__
    p = s.parse(value)
  File "/usr/lib/pymodules/python2.7/univention/admin/syntax.py", line 319, in parse
    if not text or not self.regex or self.regex.match(text) is not None:
TypeError: expected string or buffer

016-06-06 06:48:20 ERROR user_import.create_and_modify_users:158  Entry #1: UDM property 'mailHomeServer' could not be set: expected string or buffer
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/mass_import/user_import.py", line 131, in create_and_modify_users
    success = user.create(lo=self.connection)
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/models/import_user.py", line 151, in create
    return super(ImportUser, self).create(lo, validate)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 420, in create
    success = self.create_without_hooks(lo, validate)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 446, in create_without_hooks
    self.do_create(udm_obj, lo)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/user.py", line 252, in do_create
    success = super(User, self).do_create(udm_obj, lo)
  File "/usr/lib/pymodules/python2.7/ucsschool/lib/models/base.py", line 462, in do_create
    self._alter_udm_obj(udm_obj)
  File "/usr/lib/pymodules/python2.7/ucsschool/importer/models/import_user.py", line 199, in _alter_udm_obj
    raise UDMError("UDM property '{}' could not be set: {}".format(property_, exc), entry=self.entry_count, import_user=self)
UDMError: UDM property 'mailHomeServer' could not be set: expected string or buffer
2016-06-06 06:48:20 INFO  user_import.create_and_modify_users:162  ------ Created 0 users, modified 0 users. ------
2016-06-06 06:48:20 INFO  user_import.log_stats:367  ------ User import statistics ------
2016-06-06 06:48:20 INFO  user_import.log_stats:368  Read users from input data: 1
2016-06-06 06:48:20 INFO  user_import.log_stats:375  Created LegacyImportStudent: 0
2016-06-06 06:48:20 INFO  user_import.log_stats:378  Modified LegacyImportStudent: 0
2016-06-06 06:48:20 INFO  user_import.log_stats:381  Deleted LegacyImportStudent: 0
2016-06-06 06:48:20 INFO  user_import.log_stats:384  Errors: 1
2016-06-06 06:48:20 INFO  user_import.log_stats:386  Entry #: Error description
2016-06-06 06:48:20 INFO  user_import.log_stats:388    1: anton303: UDM property 'mailHomeServer' could not be set: expected string or buffer
2016-06-06 06:48:20 INFO  user_import.log_stats:389  ------ End of user import statistics ------
2016-06-06 06:48:20 INFO  mass_import.import_users:108  ------ Writing user import summary to /var/lib/ucs-school-import/user_import_summary_2016-06-06_06:48:20.csv... ------
2016-06-06 06:48:20 INFO  mass_import.import_users:110  ------ Importing users done. ------
Comment 11 Daniel Tröder univentionstaff 2016-12-07 14:59:36 CET
OK: code change
OK: advisory
OK: problem fixed for udm_attributes, problem regarding ucsschool.lib.Attributes (like email, birthday, record_uid) is split into Bug #43131
Comment 12 Sönke Schwardt-Krummrich univentionstaff 2016-12-12 13:10:20 CET
UCS@school 4.1 R2 v9 has been released.

http://docs.software-univention.de/changelog-ucsschool-4.1R2v9-de.html