Can't upload files >1MB

Hi,

I’m running the XWiki 10.7 Tomcat official docker image with a Postgres-DB.

The problem is that I can’t upload attachments larger than 1 MB even though bin/edit/XWiki/XWikiPreferences?editor=object was set to 30MB by default and is now set to 30GB or something like that.

There appears to be no log entries in tomcat/logs/ but I’m not sure what I’d be looking for and in which log file.

Thanks for all help,
Stefan

Hi, I took the time to test this and it worked fine for me.

What you did seems ok. On my side I’ve modified the max upload size from 33554432 bytes to 3355443200 (ie from 32MB to 3.2GB).

Then it started working and I could upload a 250MB file with no problem. It took about 20 seconds.

FYI starting with 10.9RC1, the default size is 100GB, I’ve just implemented http://jira.xwiki.org/browse/XWIKI-15702#

I’ve also added a few zeroes to the max upload size even though it shouldn’t have been necessary. As mentioned, it seems to fail from 1MB upwards.

The upload dialog appears, it appears to upload and to finish and then “an error occurred” if the file is larger than 1MB:

Capture

My main question: How would you debug something like this? If there is code that makes the error message appear doesn’t that code log that error somewhere?! Perhaps with a more helpful error message.

Yes you should find all problems in the xwiki log file. It’s located in your application server log file. If you use tomcat then it’s in catalina.out.

In the container there is a catalina.2018-10-10.log in the logs dir of tomcat:

root@xwiki-test-0:/usr/local/tomcat/logs# ls -la
total 192
drwxrwxrwx 1 root root    4096 Oct 10 08:56 .
drwxr-sr-x 1 root staff   4096 Sep 12 21:41 ..
-rw-r----- 1 root root   13073 Oct 10 09:22 catalina.2018-10-10.log
-rw-r----- 1 root root       0 Oct 10 08:56 host-manager.2018-10-10.log
-rw-r----- 1 root root       0 Oct 10 08:56 localhost.2018-10-10.log
-rw-r----- 1 root root  160446 Oct 10 13:51 localhost_access_log.2018-10-10.txt
-rw-r----- 1 root root       0 Oct 10 08:56 manager.2018-10-10.log

That contains nothing about the file or the upload.

root@xwiki-test-0:/usr/local/tomcat/logs# cat catalina.2018-10-10.log
10-Oct-2018 08:56:14.255 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.34
10-Oct-2018 08:56:14.257 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Sep 4 2018 22:28:22 UTC
10-Oct-2018 08:56:14.257 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.34.0
10-Oct-2018 08:56:14.257 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
10-Oct-2018 08:56:14.257 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            4.15.0-34-generic
10-Oct-2018 08:56:14.257 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
10-Oct-2018 08:56:14.257 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-8-openjdk-amd64/jre
10-Oct-2018 08:56:14.257 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_181-8u181-b13-1~deb9u1-b13
10-Oct-2018 08:56:14.257 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
10-Oct-2018 08:56:14.258 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
10-Oct-2018 08:56:14.258 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
10-Oct-2018 08:56:14.258 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
10-Oct-2018 08:56:14.258 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
10-Oct-2018 08:56:14.258 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
10-Oct-2018 08:56:14.258 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
10-Oct-2018 08:56:14.258 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
10-Oct-2018 08:56:14.258 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx1024m
10-Oct-2018 08:56:14.258 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.tomcat.util.buf.UDecoder.ALLOW_ENCODED_SLASH=true
10-Oct-2018 08:56:14.259 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.connector.CoyoteAdapter.ALLOW_BACKSLASH=true
10-Oct-2018 08:56:14.259 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dsecurerandom.source=file:/dev/urandom
10-Oct-2018 08:56:14.259 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
10-Oct-2018 08:56:14.259 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
10-Oct-2018 08:56:14.259 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
10-Oct-2018 08:56:14.259 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
10-Oct-2018 08:56:14.259 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library [1.2.17] using APR version [1.5.2].
10-Oct-2018 08:56:14.259 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
10-Oct-2018 08:56:14.259 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
10-Oct-2018 08:56:14.265 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.0f  25 May 2017]
10-Oct-2018 08:56:14.324 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
10-Oct-2018 08:56:14.332 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
10-Oct-2018 08:56:14.337 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
10-Oct-2018 08:56:14.338 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
10-Oct-2018 08:56:14.339 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 347 ms
10-Oct-2018 08:56:14.360 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
10-Oct-2018 08:56:14.360 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.34
10-Oct-2018 08:56:14.367 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/ROOT]
10-Oct-2018 08:56:25.269 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
10-Oct-2018 08:56:37.226 INFO [localhost-startStop-1] org.artofsolving.jodconverter.office.ProcessPoolOfficeManager.<init> ProcessManager implementation is LinuxProcessManager
10-Oct-2018 08:56:37.245 INFO [OfficeProcessThread-0] org.artofsolving.jodconverter.office.OfficeProcess.start starting process with acceptString 'socket,host=127.0.0.1,port=8100,tcpNoDelay=1' and profileDir '/usr/local/tomcat/temp/.jodconverter_socket_host-127.0.0.1_port-8100'
10-Oct-2018 08:56:37.254 INFO [OfficeProcessThread-0] org.artofsolving.jodconverter.office.OfficeProcess.start started process; pid = 98
10-Oct-2018 08:56:37.535 WARNING [OfficeProcessThread-0] org.artofsolving.jodconverter.office.ManagedOfficeProcess$6.attempt office process died with exit code 81; restarting it
10-Oct-2018 08:56:37.542 INFO [OfficeProcessThread-0] org.artofsolving.jodconverter.office.OfficeProcess.start starting process with acceptString 'socket,host=127.0.0.1,port=8100,tcpNoDelay=1' and profileDir '/usr/local/tomcat/temp/.jodconverter_socket_host-127.0.0.1_port-8100'
10-Oct-2018 08:56:37.553 INFO [OfficeProcessThread-0] org.artofsolving.jodconverter.office.OfficeProcess.start started process; pid = 108
10-Oct-2018 08:56:37.856 INFO [OfficeProcessThread-0] org.artofsolving.jodconverter.office.OfficeConnection.connect connected: 'socket,host=127.0.0.1,port=8100,tcpNoDelay=1'
10-Oct-2018 08:56:39.118 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/ROOT] has finished in [24,751] ms
10-Oct-2018 08:56:39.123 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
10-Oct-2018 08:56:39.171 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
10-Oct-2018 08:56:39.199 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 24860 ms
10-Oct-2018 09:22:13.529 WARNING [http://wiki.statistik-experten.de/bin/download/FlamingoThemes/Iceberg/logo.svg] org.apache.catalina.connector.Response.setCharacterEncoding The encoding [] is not recognised by the JRE
 java.lang.IllegalArgumentException: java.io.UnsupportedEncodingException: The character encoding [] is not supported

There’s also an access log. But there, too, is nothing about the upload:

10.42.128.0 - - [10/Oct/2018:13:49:10 +0000] "POST /bin/loginsubmit/XWiki/XWikiLogin HTTP/1.1" 302 -
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /bin/view/Sandbox/ HTTP/1.1" 200 50843
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /webjars/wiki%3Axwiki/xwiki-platform-tree-webjar/10.7/tree.min.css?evaluate=true HTTP/1.1" 200 31469
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /bin/get/Sandbox/WebHome?xpage=xpart&vm=commentsinline.vm HTTP/1.1" 200 3076
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /webjars/wiki%3Axwiki/xwiki-platform-tree-webjar/10.7/require-config.min.js?evaluate=true HTTP/1.1" 200 350
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /bin/download/Sandbox/WebHome/XWikiLogo.png HTTP/1.1" 404 23916
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /bin/get/XWiki/Notifications/Code/NotificationsDisplayerUIX?outputSyntax=plain&action=getUnreadCount&_=1539179350732 HTTP/1.1" 200 12
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /bin/get/TourCode/TourJson?xpage=plain&outputSyntax=plain&tourDoc=Sandbox.WebHome HTTP/1.1" 200 12
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /bin/get/Sandbox/WebHome?outputSyntax=plain&sheet=XWiki.DocumentTree&showAttachments=false&showTranslations=false&root=document%3Axwiki%3ASandbox.WebHome&showRoot=true&data=children&id=%23 HTTP/1.1" 200 439
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /bin/get/Sandbox/WebHome?outputSyntax=plain&sheet=XWiki.DocumentTree&showAttachments=false&showTranslations=false&exclusions=document%3Axwiki%3ASandbox.WebHome&exclusions=document%3Axwiki%3AHelp.WebHome&exclusions=document%3Axwiki%3AXWiki.WebHome&exclusions=document%3Axwiki%3AMenu.WebHome&data=children&id=%23HTTP/1.1" 200 425
10.42.128.0 - - [10/Oct/2018:13:49:11 +0000] "GET /bin/get/Sandbox/WebHome?outputSyntax=plain&sheet=XWiki.DocumentTree&showAttachments=false&showTranslations=false&exclusions=document%3Axwiki%3ASandbox.WebHome&exclusions=document%3Axwiki%3AHelp.WebHome&exclusions=document%3Axwiki%3AXWiki.WebHome&exclusions=document%3Axwiki%3AMenu.WebHome&data=path&id=document%3Axwiki%3ASandbox.WebHome HTTP/1.1" 200 439
10.42.128.0 - - [10/Oct/2018:13:49:14 +0000] "GET /bin/get/Sandbox/WebHome?xpage=xpart&vm=attachmentsinline.vm HTTP/1.1" 200 2512
10.42.224.0 - - [10/Oct/2018:13:49:17 +0000] "GET /bin/view/Main/ HTTP/1.1" 200 37926

Are you using the XWiki Docker image by any chance?

Yes, I do.

ok so that explains it. I’ve recently noticed that the xwiki logs do not appear in the catalina.out files when using the XWiki Docker image. I’ve just created https://jira.xwiki.org/browse/XDOCKER-78

You should have them in the console where you started “docker run” and if you ran it in the background you can issue a “docker logs”.

I get an entry in that log. Unfortunately, it’s not really helpful:

2018-10-10 14:12:20,008 [http://[...]/bin/download/Sandbox/WebHome/XWikiLogo.png] WARN c.x.x.p.XWikiPluginManager - downloadAttachment failed for plugin [image]: null
2018-10-10 14:12:20,008 [http://[...]/bin/download/Sandbox/WebHome/XWikiLogo.png] WARN c.x.x.p.XWikiPluginManager - downloadAttachment failed for plugin [zipexplorer]: null

The entry is related to the page load and not the attachment upload.

Indeed; not very useful…

I don’t know what’s the problem. All I know is that it can work since it worked when I tried the XWiki docker image so my guess is that it’s your environment. If I had to guess I’d say that it’s a permission issue in your permanent directory (the volume mapped to your host).

Sorry the reply took so long, I didn’t have the time to play with xwiki.

I did some tests and the problem was with the kubernetes ingress. The annotation

nginx.ingress.kubernetes.io/proxy-body-size: 50m

fixed it.

Thanks a lot for your help. The fact that it worked for you helped me a lot.