emptying DBPortPool to localhost/127.0.0.1:27017 b/c of error java.io.EOFException at org.bson.io.Bits.readFully(Bits.java:48)

[ronald...@versatec.de]

Hi all,

after trying for weeks to solve this issue on my own I have decided to ask for help here. Problem is my application runs perfectly unless left alone for many hours (like over night). In this case the following exception is thrown on only the first call to mongoClient (I have marked the line in my code below that throws the Exception):

[2013-11-14T08:43:35.518+0100] [glassfish 4.0] [WARNING] [] [com.mongodb] [tid: _ThreadID=21 _ThreadName=http-listener-1(4)] [timeMillis: 1384415015518] [levelValue: 900] [[
 emptying DBPortPool to localhost/127.0.0.1:27017 b/c of error
java.io.EOFException
 at org.bson.io.Bits.readFully(Bits.java:48)
 at org.bson.io.Bits.readFully(Bits.java:33)
 at org.bson.io.Bits.readFully(Bits.java:28)
 at com.mongodb.Response.<init>(Response.java:40)
 at com.mongodb.DBPort.go(DBPort.java:142)
 at com.mongodb.DBPort.call(DBPort.java:92)
 at com.mongodb.DBTCPConnector.innerCall(DBTCPConnector.java:244)
 at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:216)
 at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:288)
 at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:273)
 at com.mongodb.DBCursor._check(DBCursor.java:368)
 at com.mongodb.DBCursor._hasNext(DBCursor.java:459)
 at com.mongodb.DBCursor.hasNext(DBCursor.java:484)
 at org.mongodb.morphia.query.MorphiaIterator.hasNext(MorphiaIterator.java:43)
 at org.mongodb.morphia.query.QueryImpl.get(QueryImpl.java:408)
 at ronny.qi.shared.MongoResourceBundle$MongoResourceBundleControl.newBundle(MongoResourceBundle.java:92)
 at java.util.ResourceBundle.loadBundle(ResourceBundle.java:1436)
 at java.util.ResourceBundle.findBundle(ResourceBundle.java:1400)
 at java.util.ResourceBundle.findBundle(ResourceBundle.java:1354)
 at java.util.ResourceBundle.findBundle(ResourceBundle.java:1354)
 at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:1296)
 at java.util.ResourceBundle.getBundle(ResourceBundle.java:841)
 at ronny.qi.shared.MongoResourceBundle.<init>(MongoResourceBundle.java:32)
 at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
 at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
 at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
 at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
 at java.lang.Class.newInstance(Class.java:374)
 at java.util.ResourceBundle$Control.newBundle(ResourceBundle.java:2572)
 at java.util.ResourceBundle.loadBundle(ResourceBundle.java:1436)
 at java.util.ResourceBundle.findBundle(ResourceBundle.java:1400)
 at java.util.ResourceBundle.findBundle(ResourceBundle.java:1354)
 at java.util.ResourceBundle.findBundle(ResourceBundle.java:1354)
 at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:1296)
 at java.util.ResourceBundle.getBundle(ResourceBundle.java:1028)
 at com.sun.faces.facelets.tag.jsf.core.LoadBundleHandler.apply(LoadBundleHandler.java:225)
 at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:95)
 at javax.faces.view.facelets.DelegatingMetaTagHandler.applyNextHandler(DelegatingMetaTagHandler.java:137)
 at com.sun.faces.facelets.tag.jsf.ComponentTagHandlerDelegateImpl.apply(ComponentTagHandlerDelegateImpl.java:190)
 at javax.faces.view.facelets.DelegatingMetaTagHandler.apply(DelegatingMetaTagHandler.java:120)
 at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:95)
 at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93)
 at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:87)
 at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:312)
 at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:371)
 at com.sun.faces.facelets.impl.DefaultFacelet.include(DefaultFacelet.java:350)
 at com.sun.faces.facelets.impl.DefaultFaceletContext.includeFacelet(DefaultFaceletContext.java:199)
 at com.sun.faces.facelets.tag.ui.CompositionHandler.apply(CompositionHandler.java:169)
 at javax.faces.view.facelets.DelegatingMetaTagHandler.applyNextHandler(DelegatingMetaTagHandler.java:137)
 at com.sun.faces.facelets.tag.jsf.ComponentTagHandlerDelegateImpl.apply(ComponentTagHandlerDelegateImpl.java:190)
 at javax.faces.view.facelets.DelegatingMetaTagHandler.apply(DelegatingMetaTagHandler.java:120)
 at javax.faces.view.facelets.CompositeFaceletHandler.apply(CompositeFaceletHandler.java:95)
 at com.sun.faces.facelets.compiler.NamespaceHandler.apply(NamespaceHandler.java:93)
 at com.sun.faces.facelets.compiler.EncodingHandler.apply(EncodingHandler.java:87)
 at com.sun.faces.facelets.impl.DefaultFacelet.apply(DefaultFacelet.java:161)
 at com.sun.faces.application.view.FaceletViewHandlingStrategy.buildView(FaceletViewHandlingStrategy.java:972)
 at com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:99)
 at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101)
 at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:219)
 at javax.faces.webapp.FacesServlet.service(FacesServlet.java:647)
 at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1682)
 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:318)
 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
 at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
 at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174)
 at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:357)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:260)
 at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:188)
 at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191)
 at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:168)
 at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189)
 at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
 at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)
 at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)
 at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)
 at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)
 at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
 at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)
 at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)
 at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)
 at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)
 at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)
 at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564)
 at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544)
 at java.lang.Thread.run(Thread.java:744)

After this Exception occurs the application keeps on running smoothly until left alone again for many hours. I simply have no idea left as to how I may solve this issue; internet research did not turn up anything useful either. I hope somebody reading this has an idea what I am doing wrong.

Environment:
Glassfish 4, mongo-java-driver-2.11.3, mongoDB db version v2.4.8 Tue Nov 19 14:33:04.923 git version: a350fc38922fbda2cec8d5dd842237b904eafc14


Here is my java code:

@Singleton
@Startup
public class MongoProvider {

    @Resource(name = "nosql/qi")
    private Properties mongoProperties;
    @Produces
    @ApplicationScoped
    private static MongoClient mongoClient = null;
    @Produces
    @ApplicationScoped
    private static AdvancedDatastore adv = null;
    private static final String HOSTPORT = "host:port";
    private static final String DBNAME = "database";
    private static final String OPTIONS = "options";
    private static final Logger logger = Logger.getLogger(MongoProvider.class.getName());

    public MongoProvider() {
    }

    @PostConstruct
    public void init() {
        if (mongoClient == null) {
            Builder builder = MongoClientOptions.builder().connectionsPerHost(25).socketKeepAlive(true).autoConnectRetry(true);
            MongoClientURI uri = new MongoClientURI("mongodb://" + mongoProperties.getProperty(HOSTPORT) + "/" + mongoProperties.getProperty(DBNAME) + "?" + mongoProperties.getProperty(OPTIONS) + "&" + builder);
            try {
                mongoClient = new MongoClient(uri);
            } catch (UnknownHostException ex) {
                logger.log(Level.SEVERE, null, ex);
            }
        }
        if (adv == null && mongoClient != null) {
            adv = new DatastoreImpl(new Morphia(), mongoClient, mongoProperties.getProperty(DBNAME));
        }
    }

    public MongoClient getMongoClient() {
        return mongoClient;
    }

    public AdvancedDatastore getAdv() {
        return adv;
    }
}

@Named
@RequestScoped
public class Encompass {

    @Inject
    private AdvancedDatastore ds;
    private Tenant tenant;
    private User user;
    private String username;
    private String password;

    public Encompass() {
    }

    @PostConstruct
    public void init() {
        user = ds.find(User.class, "name", "superuser").get();                                            // this is where the above Exception is thrown
        tenant = ds.find(Tenant.class, "tenantId.id", user.getTenantId().getId()).get();
    }

    public Tenant getTenant() {
        return tenant;
    }

    public void setTenant(Tenant tenant) {
        this.tenant = tenant;
    }

    public User getUser() {
        return user;
    }

    public void setUser(User user) {
        this.user = user;
    }

    public void saveTheme() {
        ds.save(user);
    }

    public String getUsername() {
        return username;
    }

    public void setUsername(String username) {
        this.username = username;
    }

    public String getPassword() {
        return password;
    }

    public void setPassword(String password) {
        this.password = password;
    }
}

[Asya Kamsky]

Would it be problematic to catch that exception?  Since you say after it continues to run normally... 

--
--
You received this message because you are subscribed to the Google
Groups "mongodb-user" group.
To post to this group, send email to mongod...@googlegroups.com
To unsubscribe from this group, send email to
mongodb-user...@googlegroups.com
See also the IRC channel -- freenode.net#mongodb
 
---
You received this message because you are subscribed to the Google Groups "mongodb-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

[Jeff Yemin]

This indicates a network issue.   It is possible that the mongod or mongos that the client is connected to was restarted?  Have you checked the server logs for anything unusual at the time the exception is thrown in the client?

Regards,

Jeff

[ronald...@versatec.de]

I can catch the exception but the data for displaying the page is missing nonetheless. Only after the user refreshes the page does the data get read and displayed ok. So, when first displaying -> empty page, second time -> all ok.

The server (debian) does not show any errors in its log files and I do not restart the mongod anywhere I am aware of; I only initialize it once and share it from there onward. The only place I do any initialization of mongod is in my MongoProvider class - so might I be doing something wrong there? Is it perhaps wrong to use @Produces with mongod or to @Inject mongod into beans?

There is also no firewall or anything else that could interfere with network since glassfish application server and mongod run on the same server.

I imagine it could perhaps have to do with bean activation / passivation? Or with mongod closing all its connections and my code somehow passing that closed connection on via @Inject?

[ronald...@versatec.de]

The solution was so smack in my face and yet, I failed to see it: We stop all daemons in order to take file system snapshots as backup, which means mongod is stopped and restarted every night which causes this error.

@Jeff Yemin: Thank you, without your posting I would not have found my mistake.