The html output cuts off at a random point of the analytics script insertion

[danielristic]

When using this on heroku, the html output is randomly cut off before the end of the document like so:

<script type="text/javascript">
if (typeof gaJsHost == 'undefined') {
  var gaJsHost = (("https:" == document.location.protocol) ? "https://ssl." : "http://www.

The markup is cut at a random point and the remaining markup is not closed.

Any idea why?

[kangguru]

uhm. nothing that directly comes to my mind.

what rails version are you using? any other middlewares in your stack that might mess up the response?

[danielristic]

I use rails 3.2.15 and that's the only middleware in the stack.

I tried to set it up in development as well and it does the same thing of cutting the html output at a random point inside the analytics script element.

For example the first time I loaded the page it cut there:

<script type="text/javascript">
if (typeof gaJsHost == 'undefined') {
  var gaJsHost = (("https:" == document.location.protocol) ? "https://ssl." : "http://www.");
  document.write(unescape("%3Cscript src='" + gaJsHost + "google-analytics.com/ga.js' type='text/javascript'%3E%3C/script%3E"));
}
</script>
<script type="text/javascript">
try {
var pageTracker = _gat._getTracker("");
pageTracker._trackPageview();
} catch(err) {}</scri

And the second time there:

<script type="text/javascript">
if (typeof gaJsHost == 'undefined') {
  var gaJsHost = (("https:" == document.location.protocol) ? 

[kangguru]

which application server do you use?

[danielristic]

locally I use thin (version 1.6.1).

[kangguru]

still no luck ;) what ruby version?

can you also please supply the output of rake middleware maybe some gem is sneaking in there

[danielristic]

I'm using ruby version 2.0.0-p247 and here is the output of rake middleware:

> rake middleware
use ActionDispatch::Static
use Rack::Lock
use #<ActiveSupport::Cache::Strategy::LocalCache::Middleware:0x007f9be3b97770>
use Rack::Runtime
use Rack::MethodOverride
use ActionDispatch::RequestId
use Rails::Rack::Logger
use ActionDispatch::ShowExceptions
use ActionDispatch::DebugExceptions
use ActionDispatch::RemoteIp
use ActionDispatch::Reloader
use ActionDispatch::Callbacks
use ActiveRecord::ConnectionAdapters::ConnectionManagement
use ActiveRecord::QueryCache
use ActionDispatch::Cookies
use ActionDispatch::Session::CookieStore
use ActionDispatch::Flash
use ActionDispatch::ParamsParser
use ActionDispatch::Head
use Rack::ConditionalGet
use Rack::ETag
use ActionDispatch::BestStandardsSupport
use Rack::GoogleAnalytics
run MyApp::Application.routes

[kangguru]

and this happens on every request? or just sometimes or on specific actions?

[danielristic]

It happens on every request and it seems to cut at the exact same place for a given page and at a different place for different pages (but always inside one of the two script elements inserted by the gem).

I tried the gem on a different project and it did not cut. There must be something very specific with my app that does not play well with it.

[zhm]

I've spent the last 2 days digging into a similar issue before finally fixing it and finding this issue.

We run nginx + unicorn + rails 4.x with this gem on production and we were seeing truncated output. After a lot of debugging, I was able to deduce that Unicorn was sending back an incorrect Content-Length header. This was in the nginx logs:

upstream sent more data than specified in "Content-Length" header while reading upstream

It turns out that nginx was correct, and using socat to make requests directly to the unicorn socket showed that unicorn was responding with more data than specified by the Content-Length header. What's interesting, is when I remove this gem completely from the app, there is no Content-Length header at all returned by normal rails views. So, something this gem is doing is:

1. Causing a Content-Length header to be emitted by Unicorn, probably because it's making rack return a String instead of an IO object? I'm not sure...
2. Causing unicorn to miscalculated the length of the response. Is there a chance this gem is somehow altering the response after a length has been calculated?

Looking at the code for this gem, it does appear to be doing some pretty low level munging/injecting of the content at the last second, which could certainly explain some of this. In either case, I've removed the gem for now because it fixes the problem. Without changing anything else but this middleware, it changes the behavior of Unicorn (Content-Length vs no Content-Length).