Comment 1 Sönke Schwardt-Krummrich 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 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 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 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 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 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 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 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 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 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 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 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