org.apache.fop.apps.FOUserAgent takes a long time to finish

[gengstah]

Hello,

I am developing a web application that will generate a word doc. I use Mac as my development environment. I have no problems with generating the report on my Mac. Recently, I deployed the same web application in a staging environment. I encountered this issue where the generation of report takes a very long time and probably not finish processing. Stuck at FOUserAgent doing its thing.

Logs in my Mac

Code: Select all

2021-09-06 22:17:45.043  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.043  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.045  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.045  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.048  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.050  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.051  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.051  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.059  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.059  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.066  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.066  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.071  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.071  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.071  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.071  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.072  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.072  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.074  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.074  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.074  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.074  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.077  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.077  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.081  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.081  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.081  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.082  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.082  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.082  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.097  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.097  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.098  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.098  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.103  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.103  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.103  INFO 2366 --- [io-3000-exec-10] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 22:17:45.103  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@6bec03d0 is null, but we don't have that
2021-09-06 22:17:45.138  WARN 2366 --- [io-3000-exec-10] org.docx4j.fonts.RunFontSelector         : TODO: how to handle char '–' in range c>='\u2000' && c<='\u2EFF'?
2021-09-06 22:17:45.142  WARN 2366 --- [io-3000-exec-10] org.docx4j.fonts.fop.util.FopConfigUtil  : Document font Calibri (Body) is not mapped to a physical font!
2021-09-06 22:17:45.142  WARN 2366 --- [io-3000-exec-10] org.docx4j.fonts.fop.util.FopConfigUtil  : Document font Calibri Light is not mapped to a physical font!
2021-09-06 22:17:45.142  WARN 2366 --- [io-3000-exec-10] org.docx4j.fonts.fop.util.FopConfigUtil  : Document font Symbol is not mapped to a physical font!
2021-09-06 22:17:45.142  INFO 2366 --- [io-3000-exec-10] org.docx4j.fonts.PhysicalFonts           : No italic form for: Wingdings
2021-09-06 22:17:45.366  WARN 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : Hyphenation pattern not found. URI: en.
2021-09-06 22:17:45.367  WARN 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : Font "Symbol,normal,700" not found. Substituting with "Symbol,normal,400".
2021-09-06 22:17:45.368  WARN 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : Font "ZapfDingbats,normal,700" not found. Substituting with "ZapfDingbats,normal,400".
2021-09-06 22:17:45.369  WARN 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : Font "Calibri,normal,700" not found. Substituting with "any,normal,700".
2021-09-06 22:17:45.393  WARN 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : Font "Calibri,normal,400" not found. Substituting with "any,normal,400".
2021-09-06 22:17:45.752  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 5:424) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:45.753  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 5:424) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:45.827  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 7:443) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:45.827  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 7:443) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:45.868  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 9:451) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:45.868  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 9:451) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:45.927  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 11:443) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:45.988  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 13:451) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:46.018  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 15:445) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:46.018  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 15:445) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:46.026  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 17:445) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:46.026  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 17:445) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:46.078  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 19:445) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:46.137  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 21:443) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:46.151  WARN 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : Font "Courier New,normal,400" not found. Substituting with "any,normal,400".
2021-09-06 22:17:46.490  INFO 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : An fo:table  (See position 23:443) is wider than the available room in inline-progression-dimension. Adjusting end-indent based on overconstrained geometry rules (XSL 1.1, ch. 5.3.4)
2021-09-06 22:17:46.493  WARN 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : Font "Calibri,italic,400" not found. Substituting with "any,italic,400".
2021-09-06 22:17:46.631  WARN 2366 --- [io-3000-exec-10] org.apache.fop.apps.FOUserAgent          : The contents of fo:external-graphic line 1 exceed the available area in the inline-progression direction by 13616 millipoints. (See position 23:20128)
2021-09-06 22:17:47.719  INFO 2366 --- [io-3000-exec-10] o.d.jaxb.NamespacePrefixMapperUtils      : Using ri.NamespacePrefixMapperRelationshipsPart, which is suitable for the JAXB RI

...JPA stuff...

2021-09-06 22:17:47.875 DEBUG 2366 --- [io-3000-exec-10] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2021-09-06 22:17:47.875 DEBUG 2366 --- [io-3000-exec-10] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(1804913848<open>)]
2021-09-06 22:17:47.875 DEBUG 2366 --- [io-3000-exec-10] o.s.jdbc.datasource.DataSourceUtils      : Resetting read-only flag of JDBC Connection [HikariProxyConnection@1699950522 wrapping conn0: url=jdbc:h2:mem:test user=SA]
2021-09-06 22:17:47.875 DEBUG 2366 --- [io-3000-exec-10] o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
2021-09-06 22:17:47.879 DEBUG 2366 --- [io-3000-exec-10] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Found 'Content-Type:application/vnd.openxmlformats-officedocument.wordprocessingml.document' in response
2021-09-06 22:17:47.880 DEBUG 2366 --- [io-3000-exec-10] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Writing [Byte array resource [resource loaded from byte array]]
2021-09-06 22:17:47.889 DEBUG 2366 --- [io-3000-exec-10] o.s.s.w.header.writers.HstsHeaderWriter  : Not injecting HSTS header since it did not match the requestMatcher org.springframework.security.web.header.writers.HstsHeaderWriter$SecureRequestMatcher@e2cb930
2021-09-06 22:17:47.889 DEBUG 2366 --- [io-3000-exec-10] w.c.HttpSessionSecurityContextRepository : SecurityContext is empty or contents are anonymous - context will not be stored in HttpSession.
2021-09-06 22:17:47.897 DEBUG 2366 --- [io-3000-exec-10] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
2021-09-06 22:17:47.897 DEBUG 2366 --- [io-3000-exec-10] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2021-09-06 22:17:47.897 DEBUG 2366 --- [io-3000-exec-10] o.s.s.w.a.ExceptionTranslationFilter     : Chain processed normally
2021-09-06 22:17:47.897 DEBUG 2366 --- [io-3000-exec-10] s.s.w.c.SecurityContextPersistenceFilter : SecurityContextHolder now cleared, as request processing completed


Logs in staging environment, running Linux

Code: Select all

2021-09-06 07:23:34.746  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.746  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.746  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.746  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.750  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.750  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.752  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.752  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.753  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.753  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.753  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.753  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.754  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.754  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.755  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.755  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.755  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.755  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.756  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.756  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.758  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.758  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.758  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.758  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.758  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.758  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.765  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.765  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.765  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.765  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.768  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.768  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.768  INFO 1857574 --- [-nio-443-exec-8] o.docx4j.openpackaging.parts.ThemePart   : Empty typeface in font for MAJOR_EAST_ASIA
2021-09-06 07:23:34.768  INFO 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : theme font for lang org.docx4j.wml.CTLanguage@3f0076dc is null, but we don't have that
2021-09-06 07:23:34.779  WARN 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.RunFontSelector         : TODO: how to handle char '?' in range c>='\u2000' && c<='\u2EFF'?
2021-09-06 07:23:34.780  WARN 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.fop.util.FopConfigUtil  : Document font Calibri (Body) is not mapped to a physical font!
2021-09-06 07:23:34.780  WARN 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.fop.util.FopConfigUtil  : Document font Calibri Light is not mapped to a physical font!
2021-09-06 07:23:34.781  WARN 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.fop.util.FopConfigUtil  : Document font Symbol is not mapped to a physical font!
2021-09-06 07:23:34.781  WARN 1857574 --- [-nio-443-exec-8] org.docx4j.fonts.fop.util.FopConfigUtil  : Document font Wingdings is not mapped to a physical font!
2021-09-06 07:24:07.891  WARN 1857574 --- [-nio-443-exec-8] org.apache.fop.apps.FOUserAgent          : Hyphenation pattern not found. URI: en.
2021-09-06 07:24:07.893  WARN 1857574 --- [-nio-443-exec-8] org.apache.fop.apps.FOUserAgent          : Font "Symbol,normal,700" not found. Substituting with "Symbol,normal,400".
2021-09-06 07:24:07.893  WARN 1857574 --- [-nio-443-exec-8] org.apache.fop.apps.FOUserAgent          : Font "ZapfDingbats,normal,700" not found. Substituting with "ZapfDingbats,normal,400".
2021-09-06 07:24:07.894  WARN 1857574 --- [-nio-443-exec-8] org.apache.fop.apps.FOUserAgent          : Font "Calibri,normal,700" not found. Substituting with "any,normal,700".
2021-09-06 07:26:28.460  WARN 1857574 --- [-nio-443-exec-8] org.apache.fop.apps.FOUserAgent          : Font "Calibri,normal,400" not found. Substituting with "any,normal,400".


[jason]

Not enough RAM? Slow CPU?

Or soft defined limits in your application server? What are you using?

How do the specs of the staging environment compare to your Mac?

[gengstah]

Hi Jason,

Sorry I forgot to mention the specs. Here is the specs of the staging server.

Code: Select all

$ lscpu
Architecture x86_64
CPU op-mode(s) 32-bit, 64-bit
Byte Order Little Endian
Address sizes 46 bits physical, 48 bits virtual
CPU(s) 32
On-line CPU(s) list 0-31
Thread(s) per core 2
Core(s) per socket 8
Socket(s) 2
NUMA node(s) 2
Vendor ID GenuineIntel
CPU family 6
Model 79
Model name Intel(R) Xeon(R) CPU E5-2620 v4 @ 2.10GHz
Stepping 1
CPU MHz 1203.397
CPU max MHz 3000.0000
CPU min MHz 1200.0000
BogoMIPS 4200.01
Virtualization VT-x
L1d cache 512 KiB
L1i cache 512 KiB
L2 cache 4 MiB
L3 cache 40 MiB


Code: Select all

$ cat /proc/meminfo | grep Mem
MemTotal:       32841920 kB
MemFree:        13908384 kB
MemAvailable:   20447616 kB


Code: Select all

$ ps aux | grep java
user     1857574  0.4 22.6 31983192 7431028 pts/1 Sl+ 06:34   3:27 java -Xms16g -Xmx24g -Dspring.profiles.active=production -jar pentest-suite.jar


This staging server is a lot faster than my Mac

[gengstah]

Additional info. I ran jstack on the java process while generating a word document.



Seems like the java thread for generating a word document is stuck on looking up IP addresses. I ran jstack multiple times and java is still running that IP address lookup.

Here is the stacktrace of that thread.

Code: Select all

"https-jsse-nio-443-exec-1" #32 daemon prio=5 os_prio=0 tid=0x00007fe99573a000 nid=0x241130 runnable [0x00007fe9233f3000]
   java.lang.Thread.State: RUNNABLE
        at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method)
        at java.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:929)
        at java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1324)
        at java.net.InetAddress.getAllByName0(InetAddress.java:1277)
        at java.net.InetAddress.getAllByName(InetAddress.java:1193)
        at java.net.InetAddress.getAllByName(InetAddress.java:1127)
        at java.net.InetAddress.getByName(InetAddress.java:1077)
        at java.net.InetSocketAddress.<init>(InetSocketAddress.java:220)
        at sun.net.NetworkClient.doConnect(NetworkClient.java:180)
        at sun.net.www.http.HttpClient.openServer(HttpClient.java:463)
        at sun.net.www.http.HttpClient.openServer(HttpClient.java:558)
        - locked <0x0000000686fee240> (a sun.net.www.http.HttpClient)
        at sun.net.www.http.HttpClient.<init>(HttpClient.java:242)
        at sun.net.www.http.HttpClient.New(HttpClient.java:339)
        at sun.net.www.http.HttpClient.New(HttpClient.java:357)
        at sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.java:1220)
        at sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java:1156)
        at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:1050)
        at sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:984)
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1564)
        - locked <0x0000000686feca80> (a sun.net.www.protocol.http.HttpURLConnection)
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1492)
        - locked <0x0000000686feca80> (a sun.net.www.protocol.http.HttpURLConnection)
        at java.net.URL.openStream(URL.java:1045)
        at org.apache.fop.apps.io.ResourceResolverFactory$NormalResourceResolver.getResource(ResourceResolverFactory.java:224)
        at org.apache.fop.apps.io.ResourceResolverFactory$TempAwareResourceResolver.getResource(ResourceResolverFactory.java:152)
        at org.apache.fop.apps.io.ResourceResolverFactory$DefaultResourceResolver.getResource(ResourceResolverFactory.java:121)
        at org.apache.fop.apps.io.InternalResourceResolver.getResource(InternalResourceResolver.java:92)
        at org.apache.fop.apps.io.InternalResourceResolver.getResource(InternalResourceResolver.java:78)
        at org.apache.fop.hyphenation.Hyphenator.getHyphenationTreeStream(Hyphenator.java:240)
        at org.apache.fop.hyphenation.Hyphenator.getUserHyphenationTree(Hyphenator.java:192)
        at org.apache.fop.hyphenation.Hyphenator.getHyphenationTree(Hyphenator.java:83)
        at org.apache.fop.hyphenation.Hyphenator.hyphenate(Hyphenator.java:251)
        at org.apache.fop.layoutmgr.inline.LineLayoutManager.getHyphenContext(LineLayoutManager.java:1431)
        at org.apache.fop.layoutmgr.inline.LineLayoutManager.findHyphenationPoints(LineLayoutManager.java:1332)
        at org.apache.fop.layoutmgr.inline.LineLayoutManager.findOptimalBreakingPoints(LineLayoutManager.java:864)
        at org.apache.fop.layoutmgr.inline.LineLayoutManager.createLineBreaks(LineLayoutManager.java:823)
        at org.apache.fop.layoutmgr.inline.LineLayoutManager.getNextKnuthElements(LineLayoutManager.java:640)
        at org.apache.fop.layoutmgr.BlockLayoutManager.getNextChildElements(BlockLayoutManager.java:141)
        at org.apache.fop.layoutmgr.BlockStackingLayoutManager.getNextKnuthElements(BlockStackingLayoutManager.java:292)
        at org.apache.fop.layoutmgr.BlockLayoutManager.getNextKnuthElements(BlockLayoutManager.java:113)
        at org.apache.fop.layoutmgr.BlockLayoutManager.getNextKnuthElements(BlockLayoutManager.java:105)
        at org.apache.fop.layoutmgr.LocalBreaker.getNextKnuthElements(LocalBreaker.java:107)
        at org.apache.fop.layoutmgr.AbstractBreaker.getNextBlockList(AbstractBreaker.java:675)
        at org.apache.fop.layoutmgr.AbstractBreaker.getNextBlockList(AbstractBreaker.java:648)
        at org.apache.fop.layoutmgr.AbstractBreaker.doLayout(AbstractBreaker.java:385)
        at org.apache.fop.layoutmgr.StaticContentLayoutManager.doLayout(StaticContentLayoutManager.java:140)
        at org.apache.fop.layoutmgr.PageSequenceLayoutManager.layoutSideRegion(PageSequenceLayoutManager.java:232)
        at org.apache.fop.layoutmgr.PageSequenceLayoutManager.finishPage(PageSequenceLayoutManager.java:238)
        at org.apache.fop.layoutmgr.AbstractPageSequenceLayoutManager.makeNewPage(AbstractPageSequenceLayoutManager.java:287)
        at org.apache.fop.layoutmgr.PageSequenceLayoutManager.makeNewPage(PageSequenceLayoutManager.java:192)
        at org.apache.fop.layoutmgr.PageBreaker.handleBreakTrait(PageBreaker.java:633)
        at org.apache.fop.layoutmgr.PageBreaker.startPart(PageBreaker.java:511)
        at org.apache.fop.layoutmgr.AbstractBreaker.addAreas(AbstractBreaker.java:564)
        at org.apache.fop.layoutmgr.AbstractBreaker.addAreas(AbstractBreaker.java:509)
        at org.apache.fop.layoutmgr.AbstractBreaker.addAreas(AbstractBreaker.java:504)
        at org.apache.fop.layoutmgr.PageBreaker.doPhase3(PageBreaker.java:338)
        at org.apache.fop.layoutmgr.AbstractBreaker.doLayout(AbstractBreaker.java:458)
        at org.apache.fop.layoutmgr.PageBreaker.doLayout(PageBreaker.java:112)
        at org.apache.fop.layoutmgr.PageSequenceLayoutManager.activateLayout(PageSequenceLayoutManager.java:143)
        at org.apache.fop.area.AreaTreeHandler.endPageSequence(AreaTreeHandler.java:267)
        at org.apache.fop.fo.pagination.PageSequence.endOfNode(PageSequence.java:139)
        at org.apache.fop.fo.FOTreeBuilder$MainFOHandler.endElement(FOTreeBuilder.java:362)
        at org.apache.fop.fo.FOTreeBuilder.endElement(FOTreeBuilder.java:190)
        at org.docx4j.org.apache.xalan.transformer.TransformerIdentityImpl.endElement(TransformerIdentityImpl.java:1148)
        at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.endElement(AbstractSAXParser.java:609)
        at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanEndElement(XMLDocumentFragmentScannerImpl.java:1782)
        at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver.next(XMLDocumentFragmentScannerImpl.java:2967)
        at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(XMLDocumentScannerImpl.java:602)
        at com.sun.org.apache.xerces.internal.impl.XMLNSDocumentScannerImpl.next(XMLNSDocumentScannerImpl.java:112)
        at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl.java:505)
        at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:842)
        at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:771)
        at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:141)
        at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1213)
        at org.docx4j.org.apache.xalan.transformer.TransformerIdentityImpl.transform(TransformerIdentityImpl.java:518)
        at org.docx4j.utils.XmlSerializerUtil.serialize(XmlSerializerUtil.java:51)
        at org.docx4j.utils.XmlSerializerUtil.serialize(XmlSerializerUtil.java:18)
        at org.docx4j.convert.out.fo.renderers.FORendererApacheFOP.render(FORendererApacheFOP.java:247)
        at org.docx4j.convert.out.fo.renderers.FORendererApacheFOP.render(FORendererApacheFOP.java:181)
        at org.docx4j.convert.out.fo.AbstractFOExporter.postprocess(AbstractFOExporter.java:168)
        at org.docx4j.convert.out.fo.AbstractFOExporter.postprocess(AbstractFOExporter.java:47)
        at org.docx4j.convert.out.common.AbstractExporter.export(AbstractExporter.java:83)
        at org.docx4j.Docx4J.toFO(Docx4J.java:710)
        at org.docx4j.convert.out.fo.FOPAreaTreeHelper.getAreaTreeViaFOP(FOPAreaTreeHelper.java:191)
        at org.docx4j.convert.out.fo.LayoutMasterSetBuilder.fixExtents(LayoutMasterSetBuilder.java:138)
        at org.docx4j.convert.out.fo.LayoutMasterSetBuilder.getLayoutMasterSetFragment(LayoutMasterSetBuilder.java:97)
        at org.docx4j.convert.out.fo.XsltFOFunctions.getLayoutMasterSetFragment(XsltFOFunctions.java:84)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.docx4j.org.apache.xalan.extensions.ExtensionHandlerJavaPackage.callFunction(ExtensionHandlerJavaPackage.java:343)
        at org.docx4j.org.apache.xalan.extensions.ExtensionHandlerJavaPackage.callFunction(ExtensionHandlerJavaPackage.java:440)
        at org.docx4j.org.apache.xalan.extensions.ExtensionsTable.extFunction(ExtensionsTable.java:222)
        at org.docx4j.org.apache.xalan.transformer.TransformerImpl.extFunction(TransformerImpl.java:475)
        at org.docx4j.org.apache.xpath.functions.FuncExtFunction.execute(FuncExtFunction.java:208)
        at org.docx4j.org.apache.xpath.XPath.execute(XPath.java:337)
        at org.docx4j.org.apache.xalan.templates.ElemCopyOf.execute(ElemCopyOf.java:134)
        at org.docx4j.org.apache.xalan.transformer.TransformerImpl.executeChildTemplates(TransformerImpl.java:2402)
        at org.docx4j.org.apache.xalan.templates.ElemLiteralResult.execute(ElemLiteralResult.java:1376)
        at org.docx4j.org.apache.xalan.templates.ElemApplyTemplates.transformSelectedNodes(ElemApplyTemplates.java:395)
        at org.docx4j.org.apache.xalan.templates.ElemApplyTemplates.execute(ElemApplyTemplates.java:178)
        at org.docx4j.org.apache.xalan.transformer.TransformerImpl.executeChildTemplates(TransformerImpl.java:2402)
        at org.docx4j.org.apache.xalan.transformer.TransformerImpl.applyTemplateToNode(TransformerImpl.java:2272)
        at org.docx4j.org.apache.xalan.transformer.TransformerImpl.transformNode(TransformerImpl.java:1358)
        - locked <0x00000005ea335ca8> (a org.docx4j.org.apache.xml.serializer.ToXMLStream)
        at org.docx4j.org.apache.xalan.transformer.TransformerImpl.transform(TransformerImpl.java:711)
        at org.docx4j.org.apache.xalan.transformer.TransformerImpl.transform(TransformerImpl.java:1275)
        - locked <0x00000005e95d2ce8> (a java.lang.Boolean)
        at org.docx4j.org.apache.xalan.transformer.TransformerImpl.transform(TransformerImpl.java:1253)
        at org.docx4j.XmlUtils.transform(XmlUtils.java:1421)
        at org.docx4j.XmlUtils.transform(XmlUtils.java:1252)
        at org.docx4j.convert.out.common.AbstractXsltExporterDelegate.process(AbstractXsltExporterDelegate.java:66)
        at org.docx4j.convert.out.common.AbstractWmlExporter.process(AbstractWmlExporter.java:82)
        at org.docx4j.convert.out.common.AbstractWmlExporter.process(AbstractWmlExporter.java:32)
        at org.docx4j.convert.out.common.AbstractExporter.export(AbstractExporter.java:80)
        at org.docx4j.Docx4J.toFO(Docx4J.java:710)
        at org.docx4j.toc.TocGenerator.getPageNumbersMapViaFOP(TocGenerator.java:759)
        at org.docx4j.toc.TocGenerator.getPageNumbersMap(TocGenerator.java:650)
        at org.docx4j.toc.TocGenerator.populateToc(TocGenerator.java:397)
        at org.docx4j.toc.TocGenerator.generateToc(TocGenerator.java:261)
        at org.docx4j.toc.TocGenerator.generateToc(TocGenerator.java:229)
        at org.docx4j.toc.TocGenerator.generateToc(TocGenerator.java:189)


[gengstah]

Okay, so this is not a problem in docx4j or apache fop. It's a problem in the underlying host configuration.

I investigate a little more what seems to be the problem. It turned out the first nameserver configured in /etc/resolv.conf is not working. Java must have been using the first configured nameserver and wait for the response until timeout (a long timeout that keeps the application hanging). Commented out that nameserver and everything is working as expected.

[jason]

Thanks for sharing. I had wondered whether it might be something like this, but although we'd encountered something similar in XHTML import (in FlyingSaucer), it had never come up vis a vis FOP.