Fatal error with pdf file

[szanati]

The IEID for the below error is EZYQ0HHD9_97E59T

I received the following error while tying to ingest a package that contained only the pdf, xml and mets file:

error while processing 1(sip-files/05-10-2015.pdf): Fatal error: EntityRef: expecting ';' at :183.

/opt/web-services/sites/core/releases/20141117161651/lib/daitss/proc/wip/preserve.rb:26:in rescue in block in preserve' /opt/web-services/sites/core/releases/20141117161651/lib/daitss/proc/wip/preserve.rb:19:inblock in preserve'
/opt/web-services/sites/core/releases/20141117161651/lib/daitss/proc/wip/preserve.rb:18:in each' /opt/web-services/sites/core/releases/20141117161651/lib/daitss/proc/wip/preserve.rb:18:inpreserve'
/opt/web-services/sites/core/releases/20141117161651/lib/daitss/proc/wip/ingest.rb:33:in ingest' /opt/web-services/sites/core/releases/20141117161651/lib/daitss/proc/wip/process.rb:82:inblock in spawn'
/opt/web-services/sites/core/releases/20141117161651/lib/daitss/proc/wip/process.rb:66:in fork' /opt/web-services/sites/core/releases/20141117161651/lib/daitss/proc/wip/process.rb:66:inspawn'
/opt/web-services/sites/core/current/bin/pulse:161:in block in start_wips' /opt/web-services/sites/core/current/bin/pulse:158:ineach'
/opt/web-services/sites/core/current/bin/pulse:158:in start_wips' /opt/web-services/sites/core/current/bin/pulse:194:inblock in
'
/opt/web-services/sites/core/current/bin/pulse:192:in `loop'
/opt/web-services/sites/core/current/bin/pulse:192:in

[jonpitts]

Looks like a problem with the XML. Without being able to see it there may be a character that needs to be escaped. Go to line 183 of the XML file.

[szanati]

Thanks Jon. I'll take a look at line 183.

[szanati]

This is what is on line 183:

<gml:Point label="Place of Publication">

[szanati]

I was able to use this xml and use a different pdf that was from the same source but a different package that had already archived. I just updated the xml for the lines for the name of the pdf and did a checksum on the other pdf. I was able to archive this way on the test machine. It makes me think that maybe it's the pdf and not the xml.

[cchou]

Yes, the error is in processing the PDF.
"error while processing 1(sip-files/05-10-2015.pdf): Fatal error: EntityRef: expecting ';' at :183."

Can you send this PDF to the description service and see if you get any error? I guess there is some bad character embedded in the PDF metadata.

[szanati]

I did run it. Here is what I got:

Not well-formedsuccessExpected dictionary for font entry in page resource
Outlines contain recursive references.
Annotation object is not a dictionary

Here is what I got on the pdf that did archive:

Not well-formedsuccessUnexpected exception java.lang.ClassCastException
Outlines contain recursive references.
Annotation object is not a dictionary
Invalid Font entry in Resources

[cchou]

From the code, https://github.com/daitss/core/blob/master/lib/daitss/proc/wip/preserve.rb#L26, it looks like it's while processing the file so it's either description service, action plan or transformation. Anything in the logs for those services relating to this file?

Basically what core does is:

1. Send the file to the description service,
2. Send the xml returned from the description service to action plan to get the processing instruction for PDF.
3. Send the PDF to the transformation service with the processing instruction to convert the file.

There should be error logs in the those services if they encounters any problem. Or, you can call those service individually.

[szanati]

Thanks carol. I see if I see anything in the logs.

[szanati]

I did find this in the transform log for the package in question:

2015 Jun 9 09:49:13 fclnx30 Transform[9218]: INFO transform.fda.fcla.edu: location = file:/var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/1/data
2015 Jun 9 09:49:50 fclnx30 Transform[9218]: INFO transform.fda.fcla.edu: error code pid 12274 exit 1
2015 Jun 9 09:49:50 fclnx30 Transform[9218]: INFO transform.fda.fcla.edu: Rack: 192.168.36.60 - - [09/Jun/2015 09:49:50] "GET /transform/pdf_norm?location=file:/var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/1/data " 200 18288 36.3724
2015 Jun 9 09:51:39 fclnx30 Transform[9218]: INFO transform.fda.fcla.edu: Rack: 192.168.36.60 - - [09/Jun/2015 09:51:39] "GET /transform/pdf_norm " 400 38 0.0009
2015 Jun 9 09:51:39 fclnx30 Transform[9218]: INFO transform.fda.fcla.edu: location = file:/var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/1/data
2015 Jun 9 09:52:16 fclnx30 Transform[9218]: INFO transform.fda.fcla.edu: error code pid 13533 exit 1
2015 Jun 9 09:52:16 fclnx30 Transform[9218]: INFO transform.fda.fcla.edu: Rack: 192.168.36.60 - - [09/Jun/2015 09:52:16] "GET /transform/pdf_norm?location=file:/var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/1/data " 200 18289 37.0649

I had reset it and tried it again that is why it shows several errors in a short amount of time.

[jonpitts]

Can you check the description service also? These services generate metadata in XML and the error is XML related. There is probably an un-escaped ampersand in the resulting metadata from one of the services.

[szanati]

This is what I got from the describe log if that is what you mean by description services for the package:

2015 Jun 8 22:03:43 fclnx30 Describe[5300]: INFO describe.fda.fcla.edu: Rack: 192.168.36.60 - - [08/Jun/2015 22:03:43] "GET /describe?location=file:/var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/2/data&uri=info%3Afda%2FEPU5LDS3K_TCXIEF%2Ffile%2F2&originalName=sip-files%2FUF00028308_02603.mets HTTP/1.0" 200 3515 0.0901
2015 Jun 8 22:03:43 fclnx30 Describe[5288]: INFO describe.fda.fcla.edu: transforming JHOVE output to DocMD

2015 Jun 8 22:03:43 fclnx30 Describe[5288]: INFO describe.fda.fcla.edu: Rack: 192.168.36.60 - - [08/Jun/2015 22:03:43] "GET /describe?location=file:/var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/1/data&uri=info%3Afda%2FEPU5LDS3K_TCXIEF%2Ffile%2F1&originalName=sip-files%2F05-10-2015.pdf HTTP/1.0" 200 213993 0.7045

2015 Jun 9 09:49:13 fclnx30 Describe[5300]: INFO describe.fda.fcla.edu: Rack: 192.168.36.60 - - [09/Jun/2015 09:49:13] "GET /describe?location=file:/var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/1/data&uri=info%3Afda%2FEPU5LDS3K_TCXIEF%2Ffile%2F1&originalName=sip-files%2F05-10-2015.pdf HTTP/1.0" 200 213993 0.7857
2015 Jun 9 09:51:38 fclnx30 Describe[5288]: INFO describe.fda.fcla.edu: transforming JHOVE output to DocMD

2015 Jun 9 09:51:39 fclnx30 Describe[5288]: INFO describe.fda.fcla.edu: Rack: 192.168.36.60 - - [09/Jun/2015 09:51:39] "GET /describe?location=file:/var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/1/data&uri=info%3Afda%2FEPU5LDS3K_TCXIEF%2Ffile%2F1&originalName=sip-files%2F05-10-2015.pdf HTTP/1.0" 200 213993 0.7347

[jonpitts]

That all looks fine. I'd lean toward the issue being in Transform.

Can you check the contents of file:/var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/1/data? I think it should be in xml format. If so, look at line 183.

[szanati]

I see these two items in /var/daitss/data/work/EPU5LDS3K_TCXIEF/files/original/1/
data metadata/
When I try to cat data its a bunch of items I can not read. I believe data is the pdf. Now in metadata there is:
aip-path describe-agent describe-bitstream-objects describe-event describe-file-object sip-path virus-check-agent virus-check-event

[jonpitts]

You can look at those but my fear is that the XML is not being created/saved. Looking back at the previous issues it could be something similar to a fix Carol put in Describe:
#250
This may require some debugging to get the resulting metadata from Transform and putting in a fix. Carol might have a better feel for the issue. It seems like there should be better logging for Transform.

[szanati]

Thanks for all your help.