[MGNLDAM-679] Broken pipe when video is loaded Created: 18/Nov/16  Updated: 04/Sep/17  Resolved: 01/Sep/17

Status: Closed
Project: Magnolia DAM Module
Component/s: None
Affects Version/s: 2.2.1
Fix Version/s: 2.2.7

Type: Bug Priority: Neutral
Reporter: Maxime Michel Assignee: Federico Grilli
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Tomcat 8.5.5


Attachments: Text File log-new.txt     Text File log-old.txt    
Issue Links:
relation
is related to MAGNOLIA-3855 h.264 (mp4) video in a html 5 video t... Closed
is related to MGNLDAM-700 DamDownloadServlet returns HTTP 200 w... Closed
is related to MGNLDAM-729 Reduce severity of random 'broken pip... Closed
Template:
Acceptance criteria:
Empty
Task DoD:
[ ]* Doc/release notes changes? Comment present?
[ ]* Downstream builds green?
[ ]* Solution information and context easily available?
[ ]* Tests
[ ]* FixVersion filled and not yet released
[ ]  Architecture Decision Record (ADR)
Bug DoR:
[ ]* Steps to reproduce, expected, and actual results filled
[ ]* Affected version filled
Date of First Response:
Sprint: Basel 110, Basel 111
Story Points: 8

 Description   

Recently the following exception has been showing up in the log when clicking around the demo (and especially, but not necessarily, on the About page, which is displaying a video). It seems to happen when the video is being loaded, but no longer when it's cached. (Using a new private session in a different browser seems to trigger it reliably.) It may have to do with MTE-93. By adding controls automatically to video components, we may have made browsers try to fetch the video more aggressively. Below is the short version of the exception. Attached are the longer version (when log level is set to debug), and a similar exception pointed by fgrilli, from MAGNOLIA-3855.

2016-11-18 11:45:14,426 INFO  info.magnolia.dam.core.download.DamDownloadServlet: Download of document [grca-over15-432.mp4]was interrupted due: java.io.IOException: Broken pipe:java.io.IOException: Broken pipe. To see more details change logging level to debug.
org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe


 Comments   
Comment by Jan Haderka [ 21/Nov/16 ]

Looks like what happens is this:

  1. page loads the video component
  2. setting controls to enabled in component, it triggers loading the video using ranges
  3. moving to next page (while some ranges or the video are still being loaded by the browser) causes browser to stop downloading now obsolete video ranges
  4. resulting in ClientAbortException

IMO solution should be just to reduce log level from INFO to DEBUG level as this is perfectly valid scenario.

Comment by Federico Grilli [ 22/Nov/16 ]

For the records, I tried to disable video controls still the exception is thrown. It may be the HTML5 video tag attribute preload (we use the default auto there) to trigger loading the video using ranges but cannot verify atm. At any rate, the issue doesn't show up on our demo where we use Tomcat 7.0.47 instead of the 8.5.5 version we sport in M5.5 bundles.

UPDATE


Apparently the issue is only with Tomcat 8.5.5. Locally I have 8.5.6 and the issue did not show up. Changed to 8.5.5 and could see the exception in the logs. Looked at the release notes for 8.5.6 but could not find anything related.

Comment by Maxime Michel [ 07/Apr/17 ]

While I was testing MAGNOLIA-7000 with a large (400MB) video file, I noticed that this message is output a lot! (3-5x a second) The page also stalls before the video is completely loaded. The video is also not available in Safari.

Comment by Philip Mundt [ 23/Aug/17 ]

Also see bundle builds https://jenkins.magnolia-cms.com/view/Product_Team/job/magnolia-bundle_5.5.x-branch/34/

Comment by Maxime Michel [ 30/Aug/17 ]

Reopening because the error is still there. I'm not sure what happened, it seemed good in PIQA.

1. install a clean bundle
2. upload a 800MB MP4 video (e.g. brew install youtube-dl && youtube-dl -f 22 https://www.youtube.com/watch?v=pfTvvLObtSc)
3. add it to an empty page
4. preview the page

Comment by Federico Grilli [ 30/Aug/17 ]

Unfortunately I can reproduce the issue with the large file provided by Maxime. Since MGNLDAM-700 we're rethrowing any IO exception as a ServletException, see
https://git.magnolia-cms.com/projects/MODULES/repos/dam/diff/magnolia-dam-core/src/main/java/info/magnolia/dam/core/download/DamDownloadServlet.java?until=c046773bc97830d478ba35cea7461c0e2fe09f80 and
https://git.magnolia-cms.com/projects/MODULES/repos/dam/commits/556587cf6deb6d3d6fd9e0fbf656edb5a0e75f33#magnolia-dam-core/src/main/java/info/magnolia/dam/core/download/DamDownloadServlet.java

Not sure that's what we actually want but it definitely is no longer enough to just log the exception at debug level.

Comment by Federico Grilli [ 31/Aug/17 ]

After further investigation here's what I found

  • "Culprit" seems to be RangeSupportFilter (if disabled no exception but then video streaming doesn't work on e.g. Safari).
  • Can't find who's closing the stream. Doesn't seem to be on our side. Can't find any obvious mistakes in RangeSupportFilter and RangedOutputStream. Maybe on Tomcat side?
  • Error seems to be harmless anyway, video is streamed correctly.
  • Workaround: check if response is partial (status==206) and skip throwing IO exception

UPDATE:
In reply to myself regarding the fact that we throw an ServletException when an IOException is encountered, apparently that is perfectly legit, as per https://docs.oracle.com/javaee/7/api/javax/servlet/Filter.html#doFilter-javax.servlet.ServletRequest-javax.servlet.ServletResponse-javax.servlet.FilterChain-
One may object that we should re-throw it as is, instead of wrapping it in a ServletException but that would not change the outcome in our case.

Comment by Federico Grilli [ 01/Sep/17 ]

Reopening as the second fix is clearly incomplete, if not plain wrong. The issue occurred again on jenkins https://jenkins.magnolia-cms.com/job/magnolia-bundle_trunk/6492/info.magnolia.bundle.test$magnolia-integration-tests/console

This time no video is involved rather the downloading of some small image on the STK's demo-features we use in our integration tests. The issue has randomly occurred on Jenkins in the past, at least since MGNLDAM-700, that is since we log the IOException as an error which, of course, causes the web crawler parser to fail. We were led astray by the video streaming because that was reproducible on our travel-demo but apparently the problem is not only about videos.

Comment by Federico Grilli [ 01/Sep/17 ]

Resolving the issue again with no changes.


I'm not able to reproduce the issue with images. I also tried installing STK to be closer to the environment integration tests are running on but no dice. At this point I suspect that, apart from the actual issue concerning the streaming video and which was fixed by the latest PR, the problem lies in HtmlUnit, the headless browser we use in our integration tests, or in Tomcat.
We could try

  • updating HtmlUnit to latest version 2.27 (we're on 2.11)
  • closing WebClient instances as explained here http://htmlunit.sourceforge.net/faq.html#MemoryLeak (not that it's strictly related to our issue but shouldn't hurt anyway)
  • use Jetty instead of Tomcat? Locally integration tests use Jetty and so far passed with no problem. On Jenkins, for some reason, we need to use Tomcat and there, now and then, we have this issue.
  • WebCrawler could skip any DamDownloadServlet error :/
Comment by Maxime Michel [ 04/Sep/17 ]

Closing this ticket because the 'reliable error triggered by videos (locally)' has been fixed. We still see the same exception show up, but randomly, on Jenkins, and with images. A follow-up will be created for that.

Generated at Mon Feb 12 05:02:12 CET 2024 using Jira 9.4.2#940002-sha1:46d1a51de284217efdcb32434eab47a99af2938b.