kitodo / kitodo-production

Kitodo.Production is a workflow management tool for mass digitization and is part of the Kitodo Digital Library Suite.
http://www.kitodo.org/software/kitodoproduction/
GNU General Public License v3.0
64 stars 63 forks source link

Printing batch docket results in error page #453

Closed henning-gerhardt closed 8 years ago

henning-gerhardt commented 8 years ago

After selecting a batch and start to print a docket of this selected batch, the browser shows only a 404 error page (File not found) as generating of PDF are failing.

docket_multipage.xsl is inside configured xsltFolder directory and is not modified.

I could track it down to line 240 in ExportXmlLog class.

If I sorround this piece of code with a try catch block and let me output the stack trace, following trace appear

org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [de.sub.goobi.beans.Benutzer#0]
    at org.hibernate.internal.SessionFactoryImpl$1$1.handleEntityNotFound(SessionFactoryImpl.java:247)
    at org.hibernate.proxy.AbstractLazyInitializer.checkTargetState(AbstractLazyInitializer.java:171)
    at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:164)
    at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:195)
    at org.hibernate.proxy.pojo.javassist.JavassistLazyInitializer.invoke(JavassistLazyInitializer.java:185)
    at de.sub.goobi.beans.Benutzer_$$_javassist_12.getNachVorname(Benutzer_$$_javassist_12.java)
    at org.goobi.production.export.ExportXmlLog.createDocument(ExportXmlLog.java:241)
    at org.goobi.production.export.ExportXmlLog.startExport(ExportXmlLog.java:489)
    at org.goobi.production.export.ExportDocket.startExport(ExportDocket.java:104)
    at de.sub.goobi.forms.BatchForm.downloadDocket(BatchForm.java:252)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
...

Mentioned line 241 in ExportXmlLog is line 240 in unmodified file.

henning-gerhardt commented 8 years ago

Affected version: Goobi.Production CE 1.11.x, current GitHub master and maybe Goobi.Production CE 1.10.x

matthias-ronge commented 8 years ago

As far as I understand ExportXmlLog ll. 240−244 catching and throwing away the exception should result in the intended behaviour.

This may be an inconsitency between the two methods of database access. StepObject declares bearbeitungsbenutzer as int, which so can never be null. It is persisted in MySQLHelper ll. 270−280. May be that a step without a user associated may be set to 0 here, and the Hibernate part then tries to load an absent user with row number 0. Do you eventually have debug log lines from MySQLHelper containing saving step: which can prove this?

matthias-ronge commented 8 years ago

Hibernate bug HHH-7205. Hibernate should return null here and not throw an exception. Recommended work-around is to wrap the problematic section in a try/catch block.

henning-gerhardt commented 8 years ago

I can't follow your analysis.

ExportXmlLog in lines L218-L250 are using bean based objects, so object s is from de.sub.goobi.beans.Schritte and has method getBearbeitungsbenutzer(). Method getBearbeitungsbenutzer() is returning a class object Benutzer from de.sub.goobi.beans.Benutzer which have a method called getNachVorname().

Why now calling s.getBearbeitungsbenutzer().getNachVorname() is causing an error, is a good question.

I set a debugging breakpoint in MySQL Helper method updateStep() but this method is never called while printing a docket for a batch nor a message got logged.

matthias-ronge commented 8 years ago

This is due to how hibernate works. The object returned from s.getBearbeitungsbenutzer() is in fact a subclass of the Benutzer object generated by Hibernate at runtime (class name: Benutzer_$$_javassist_12). This so-called proxy object does not contain any data, just the row number from the BearbeitungsBenutzerID field of the Schritt object. The real object is not loaded from the database until it is accessed. This is called lazy initialization. In the moment you access getNachVorname() Hibernate tries to load the object, finds out that there is no row 0 in the table benutzer and throws an exception. (This behaviour is also reflected in the stack trace.)

My analysis was about how the 0 could have come into the BearbeitungsBenutzerID field. It should not be there, I think, the field value should probably be null, obviously 0 is interpreted as an acceptable row number. Or someone deleted the user account which was row 0 on your system. But I assume the 0 came there automatically. If so, it’s a bug.

henning-gerhardt commented 8 years ago

Thank you for this explanation. I saw while debugging some lazy init usage but misinterpreted this.

I will debug this deeper to get some more information.

henning-gerhardt commented 8 years ago

Maybe I found an explanation why there is a 0 instead of NULL:

I see there tree different solutions:

  1. fix reason why in case of an open step BearbeitungsBenutzerID is 0 and not NULL
  2. adding a try catch block to catch exceptions
  3. add an additional condition to check step state and only for non-open states try to get the user of this step
henning-gerhardt commented 8 years ago

In commit https://github.com/henning-gerhardt/goobi-production/commit/431369beef6f7684eb1bc1ca72fea2b2e69efa8c I implemented solution three.

Maybe there is an way to implement solution one?

henning-gerhardt commented 8 years ago

@matthias-ronge : Want is your opinion to my change or in general my proposed solutions?

henning-gerhardt commented 8 years ago

Some notes and maybe possible bugs:

henning-gerhardt commented 8 years ago

An other curiosity: automatic steps could have an user assigned with id 0. This id value caused even a hibernate exception.