UNKNOWN org.sonatype.nexus.repository.httpbridge.internal.ViewServlet - Failure servicing: GET

[ssofia]

Hello,

My Nexus OSS version is 3.7.1 - 02

I see error in the log file that it can service package nuget.commandline version 2.0.0. The package is in repo and I can download it manually. 

The full error looks like this:

2018-03-13 05:12:52,016-0700 WARN  [qtp1351088239-143572]  *UNKNOWN org.sonatype.nexus.repository.httpbridge.internal.ViewServlet - Failure servicing: GET /repository/nuget-group/FindPac

kagesById()?id='nuget.commandline'&semVerLevel=2.0.0

org.eclipse.jetty.io.EofException: null

        at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:199)

        at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:420)

        at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:313)

        at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:147)

        at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:745)

        at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)

        at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224)

        at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:519)

        at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:737)

        at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:788)

        at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:235)

        at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:219)

        at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:470)

        at com.google.common.io.ByteStreams.copy(ByteStreams.java:110)

        at org.sonatype.nexus.repository.httpbridge.internal.DefaultHttpResponseSender.send(DefaultHttpResponseSender.java:83)

        at org.sonatype.nexus.repository.httpbridge.internal.ViewServlet.dispatchAndSend(ViewServlet.java:216)

        at org.sonatype.nexus.repository.httpbridge.internal.ViewServlet.doService(ViewServlet.java:162)

        at org.sonatype.nexus.repository.httpbridge.internal.ViewServlet.service(ViewServlet.java:119)

        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)

        at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:286)

        at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:276)

        at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:181)

        at com.google.inject.servlet.DynamicServletPipeline.service(DynamicServletPipeline.java:71)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85)

        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:112)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)

        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)

        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)

        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)

        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)

        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)

        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)

        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)

        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)

        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)

        at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)

        at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)

        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)

        at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)

        at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)

        at org.sonatype.nexus.security.SecurityFilter.executeChain(SecurityFilter.java:85)

        at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)

        at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)

        at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)

        at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383)

        at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)

        at org.sonatype.nexus.security.SecurityFilter.doFilterInternal(SecurityFilter.java:101)

        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)

        at org.sonatype.nexus.repository.httpbridge.internal.ExhaustRequestFilter.doFilter(ExhaustRequestFilter.java:71)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)

        at com.sonatype.nexus.licensing.internal.LicensingRedirectFilter.doFilter(LicensingRedirectFilter.java:108)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)

        at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:97)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82

               at org.sonatype.nexus.internal.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:68)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)

        at org.sonatype.nexus.internal.web.EnvironmentFilter.doFilter(EnvironmentFilter.java:102)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)

        at org.sonatype.nexus.internal.web.HeaderPatternFilter.doFilter(HeaderPatternFilter.java:98)

        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)

        at com.google.inject.servlet.DynamicFilterPipeline.dispatch(DynamicFilterPipeline.java:104)

        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:135)

        at org.sonatype.nexus.bootstrap.osgi.DelegatingFilter.doFilter(DelegatingFilter.java:73)

        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1751)

        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)

        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)

        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)

        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)

        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)

        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)

        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)

        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)

        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)

        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)

        at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:175)

        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119)

        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)

        at org.eclipse.jetty.server.Server.handle(Server.java:534)

        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)

        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)

        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)

        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)

        at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)

        at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)

        at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)

        at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)

        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)

        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)

        at java.lang.Thread.run(Thread.java:745)

Caused by: java.io.IOException: Broken pipe

        at sun.nio.ch.FileDispatcherImpl.write0(Native Method)

        at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)

        at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)

        at sun.nio.ch.IOUtil.write(IOUtil.java:51)

        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471)

        at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:177)

It's a summary of tha package from the repo:

Repository	nuget-group
Format	nuget
Component Name	NuGet.CommandLine
Component Version	2.0.0
Path	NuGet.CommandLine/2.0.0
Content type	application/zip
File size	274 KB
Blob created	Mon Mar 12 2018 16:33:34 GMT-0700 (PDT)
Blob updated	Mon Mar 12 2018 16:33:34 GMT-0700 (PDT)
Last 30 days	0 downloads
Last downloaded	Mon Mar 12 2018 16:33:33 GMT-0700 (PDT)
Locally cached	true
Blob reference	default@3825FE36-5F816F7E-98BEABE2-A412DF86-29825BA7:a4f4100b-9100-47d7-9878-e7420afc11ea
Containing repo	nuget.org-proxy
Uploader	user
Uploader's IP Address	10.32.109.121
Most popular version	4.5.1
Age	5.7 yrs

Any help appreciated.

Thank you.

[msu...@sonatype.com]

Hi,


A broken pipe exception occurs when Nexus is trying to write a response out to the client, therefore the client or reverse proxy in front Nexus is terminating the connection. If you are using a reverse proxy, then check the reverse proxy logs.

Regards,

Mahendra

[Brantone]

In my case, Nginx logs:

2018/05/11 02:16:06 [error] 19453#19453: *189327 upstream prematurely closed connection while reading response header from upstream, client: **internal.ip**, server: nexus-https, request: "GET /repository/nuget-nuget.org/System.Collections/4.0.11 HTTP/1.1", upstream: "http://127.0.0.1:8081/repository/nuget-nuget.org/System.Collections/4.0.11", host: "**internal-url**"

First thing to catch my eye is: upstream prematurely closed connection

[Rich Seddon]

Check your nginx configuration, and make sure you're using our recommended settings:

https://help.sonatype.com/display/NXRM3/Run+Behind+a+Reverse+Proxy#RunBehindaReverseProxy-nginx

In particular, be sure to turn off proxy_buffering, that can cause this.

--
You received this message because you are subscribed to the Google Groups "Nexus Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to nexus-users+unsubscribe@glists.sonatype.com.
To post to this group, send email to nexus...@glists.sonatype.com.
To view this discussion on the web visit https://groups.google.com/a/glists.sonatype.com/d/msgid/nexus-users/b6342ea1-4a4b-4373-aab2-acb4fa0773f9%40glists.sonatype.com.

For more options, visit https://groups.google.com/a/glists.sonatype.com/d/optout.

[Brantone]

Yup, all set up like that (minor tweak for obvious things like server name).

Fwiw, this usually only spikes high when doing NuGet restore, meaning: fetching bunch of packages.

Anyone know what the numbers "19453#19453: *189327" represent ?... I'm theorizing if each request for package is distinct/separate rather than re-using connection (though keepalive_requests is at 10000)

Still though, mention of  "upstream prematurely closing", doesn't that mean it's Nexus that's closing it?

On Friday, 11 May 2018 07:02:41 UTC-7, Rich Seddon wrote:

Check your nginx configuration, and make sure you're using our recommended settings:

https://help.sonatype.com/display/NXRM3/Run+Behind+a+Reverse+Proxy#RunBehindaReverseProxy-nginx

In particular, be sure to turn off proxy_buffering, that can cause this.

On Fri, May 11, 2018 at 2:35 AM, Brantone <bre...@letrabb.com> wrote:

In my case, Nginx logs:

2018/05/11 02:16:06 [error] 19453#19453: *189327 upstream prematurely closed connection while reading response header from upstream, client: **internal.ip**, server: nexus-https, request: "GET /repository/nuget-nuget.org/System.Collections/4.0.11 HTTP/1.1", upstream: "http://127.0.0.1:8081/repository/nuget-nuget.org/System.Collections/4.0.11", host: "**internal-url**"

First thing to catch my eye is: upstream prematurely closed connection

On Wednesday, 14 March 2018 03:32:29 UTC-7, msu...@sonatype.com wrote:

Hi,


A broken pipe exception occurs when Nexus is trying to write a response out to the client, therefore the client or reverse proxy in front Nexus is terminating the connection. If you are using a reverse proxy, then check the reverse proxy logs.

Regards,

Mahendra

--
You received this message because you are subscribed to the Google Groups "Nexus Users" group.

To unsubscribe from this group and stop receiving emails from it, send an email to nexus-users...@glists.sonatype.com.

To post to this group, send email to nexus...@glists.sonatype.com.

[Rich Seddon]

Still though, mention of  "upstream prematurely closing", doesn't that mean it's Nexus that's closing it?

Yes, nginx is saying Nexus closed it.  

But on the Nexus side we see:

Caused by: java.io.IOException: Broken pipe

        at sun.nio.ch.FileDispatcherImpl.write0(Native Method)

        at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)

        at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)

        at sun.nio.ch.IOUtil.write(IOUtil.java:51)

        at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471)

        at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:177)

Which clearly shows that Nexus is writing content to the socket, and suddenly finds the socket has been closed on it.

To unsubscribe from this group and stop receiving emails from it, send an email to nexus-users+unsubscribe@glists.sonatype.com.

To post to this group, send email to nexus...@glists.sonatype.com.

To view this discussion on the web visit https://groups.google.com/a/glists.sonatype.com/d/msgid/nexus-users/32556d24-25a9-45b7-bef6-5ec14287be0a%40glists.sonatype.com.

[Brantone]

Hmmm ... in my scenario, not seeing a line-up for log times between Nexus <-> Nginx , and in fact seeing more occurrences of the "org.eclipse.jetty.io.EofException: null" than errors in Nginx.

So essentially saying: still looks like an issue with Nexus more than proxy/Nginx side.

[Rich Seddon]

Oh sorry, I didn't notice you'd piggybacked this discussion on something reported by a different person.  I'd suggest filing an issue at https://issues.sonatype.org in the "dev - nexus" project so we can examine your logs.

To unsubscribe from this group and stop receiving emails from it, send an email to nexus-users+unsubscribe@glists.sonatype.com.

To post to this group, send email to nexus...@glists.sonatype.com.

To view this discussion on the web visit https://groups.google.com/a/glists.sonatype.com/d/msgid/nexus-users/679f5122-646f-4b6c-a8a4-ae05a2b32393%40glists.sonatype.com.

[Brantone]

I'm gonna try updating to latest version and see how it goes ...

My error log is near identical to OP's  and initial response was to check reverse proxy; which after doing so, the issue still occurs ... so kinda pointing fingers between Nginx and Nexus who's fault it is :/

We'll see what happens after 3.11.0-01.

[Mariska]

I just had this same issue (with nexus 3.12.0-01) and apache reverse proxy 2.4. However, after several of these errors in the logfile, Nexus completely became unresponsive with about 8 heap errors messages like the following all concerning nuget repository:

2018-06-28 16:23:51,179+0200 ERROR [qtp129695958-21487]  *UNKNOWN com.google.common.eventbus.EventBus.nexus - Could not dispatch event Co
mponentCreatedEvent{metadata=AttachedEntityMetadata{schema=component, document=component#48:9037{bucket:#40:1,format:nuget,last_updated:T
hu Jun 28 16:23:27 CEST 2018,attributes:[1],group:null,name:FAKE.Deploy.Lib,version:2.4.0.0,ci_name:fake.deploy.lib} v1}, remoteNodeId=nu
ll} to subscriber com.sonatype.nexus.repository.nuget.internal.proxy.NugetProxyGalleryFacet$$EnhancerByGuice$$76b24085@746661fc method [p
ublic void com.sonatype.nexus.repository.nuget.internal.NugetLocalGalleryFacetSupport.on(org.sonatype.nexus.repository.storage.ComponentC
reatedEvent)]

com.orientechnologies.orient.core.exception.OCommandExecutionException: Cannot execute query "SELECT FROM component WHERE (name = "FAKE.D
eploy.Lib" ) AND (bucket = #40:1 )": low heap memory

        DB name="component"

        at com.orientechnologies.orient.core.sql.OSoftQueryResultList.throwCanExecuteException(OSoftQueryResultList.java:688)

        at com.orientechnologies.orient.core.sql.OSoftQueryResultList.checkQueue(OSoftQueryResultList.java:78)

        at com.orientechnologies.orient.core.sql.OSoftQueryResultList.size(OSoftQueryResultList.java:88)

        at java.util.Collections$SynchronizedCollection.size(Collections.java:2015)

        at com.orientechnologies.orient.core.sql.query.OBasicResultSet.size(OBasicResultSet.java:66)

        at com.orientechnologies.orient.core.sql.query.OBasicResultSet$1.hasNext(OBasicResultSet.java:86)

<>

And then an out-of-memory error 

2018-06-28 16:24:07,342+0200 ERROR [qtp129695958-21483]  *UNKNOWN org.sonatype.nexus.orient.entity.EntityHook - Failed to post entity eve
nts

java.lang.OutOfMemoryError: GC overhead limit exceeded

        at java.util.concurrent.ArrayBlockingQueue.<init>(ArrayBlockingQueue.java:255)

        at java.util.concurrent.ArrayBlockingQueue.<init>(ArrayBlockingQueue.java:239)

        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.<init>(OCommandExecutorSQLSelect.java:143)

        at sun.reflect.GeneratedConstructorAccessor98.newInstance(Unknown Source)

        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)

        at java.lang.Class.newInstance(Class.java:442)

        at com.orientechnologies.orient.core.sql.ODefaultCommandExecutorSQLFactory.createCommand(ODefaultCommandExecutorSQLFactory.java:1
29)

        at com.orientechnologies.orient.core.sql.OSQLEngine.getCommand(OSQLEngine.java:451)

        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.parse(OCommandExecutorSQLDelegate.java:47)

        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.parse(OCommandExecutorSQLDelegate.java:34)

        at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.command(OAbstractPaginatedStorage.java:3301)

        at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:69)

        at org.sonatype.nexus.repository.storage.AssetEntityAdapter.browseByComponent(AssetEntityAdapter.java:288)

   

Just to be sure, I upgraded to the latest 3.12.1-01, but it worries me a bit that I had to restart nexus to get it working again. In the apache logs, I see a lot of nuget traffic arround the time of the errors (other timesettings, 14:13 matches 16.13 in nexus log.

Thu Jun 28 14:13:37.865573 2018] [proxy_http:error] [pid 244:tid 140576636700416] (70007)The timeout specified has expired: [client 10.1
03.19.58:63411] AH01102: error reading status line from remote server cm-nexus:8081

I could increase the timeout, but nexus should not become unresponsive in this situation.

Any suggestions are appreciated.

[Rich Seddon]

Have you allocated memory to Nexus according to our requirements as outlined here?

https://help.sonatype.com/display/NXRM3/System+Requirements#SystemRequirements-Memory

[Mariska]

Yes, we've got a medium team configuration:

• repositories < 50
  
• total blobstore size < 200GB
  
• a few repository formats
  

with 8GB memory and the following JVM settings: -Xms2703M -Xmx2703M -XX:MaxDirectMemorySize=2703M

Actual sizes:

• blobstore: 80GB
  
• 24 hosted repositories
• 7 group repositories
• 12 proxy repositories

[Rich Seddon]

This doesn't seem like something that will be resolvable via this forum.  I'd suggest filing an issue at https://issues.sonatype.org in the "dev - nexus repo" project.