warning when running on continuous while loop

[Martinus Martinus]

Hi,

I'm using hadoop-mongo plugin to do parallel querying and updating, but when I put this process into a continuous while loop, I got this warning :

Conf: Configuration: core-default.xml, core-site.xml, mapred-default.xml, mapred-site.xml
12/01/11 12:13:28 INFO jvm.JvmMetrics: Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
12/01/11 12:13:28 WARN mapred.JobClient: Use GenericOptionsParser for parsing the arguments. Applications should implement Tool for the same.
12/01/11 12:13:28 WARN mapred.JobClient: No job jar file set.  User classes may not be found. See JobConf(Class) or JobConf#setJar(String).
Jan 11, 2012 12:13:29 PM com.mongodb.DBTCPConnector fetchMaxBsonObjectSize
WARNING: Exception determining maxBSON size using0
java.io.EOFException
    at org.bson.io.Bits.readFully(

Bits.java:37)
    at org.bson.io.Bits.readFully(Bits.java:28)
    at com.mongodb.Response.<init>(Response.java:39)
    at com.mongodb.DBPort.go(DBPort.java:123)
    at com.mongodb.DBPort.go(DBPort.java:82)
    at com.mongodb.DBPort.findOne(DBPort.java:142)
    at com.mongodb.DBPort.runCommand(DBPort.java:151)
    at com.mongodb.DBTCPConnector.fetchMaxBsonObjectSize(DBTCPConnector.java:429)
    at com.mongodb.DBTCPConnector.checkMaster(DBTCPConnector.java:416)
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:193)
    at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:303)
    at com.mongodb.DB.command(DB.java:159)
    at com.mongodb.DBCollection.getStats(DBCollection.java:1038)
    at com.mongodb.hadoop.util.MongoSplitter.calculateSplits(MongoSplitter.java:52)
    at com.mongodb.hadoop.MongoInputFormat.getSplits(MongoInputFormat.java:51)
    at org.apache.hadoop.mapred.JobClient.writeNewSplits(JobClient.java:885)
    at org.apache.hadoop.mapred.JobClient.submitJobInternal(JobClient.java:779)
    at org.apache.hadoop.mapreduce.Job.submit(Job.java:432)
    at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:447)
    at com.xxxx.extract.ExtractHadoop.get_data(ExtractHadoop.java:289)
    at com.xxxx.extract.Extract.main(Extract.java:31)
Jan 11, 2012 12:13:29 PM com.mongodb.DBPortPool gotError
WARNING: emptying DBPortPool to 172.16.2.148:27017 b/c of error
java.io.EOFException
    at org.bson.io.Bits.readFully(Bits.java:37)
    at org.bson.io.Bits.readFully(Bits.java:28)
    at com.mongodb.Response.<init>(Response.java:39)
    at com.mongodb.DBPort.go(DBPort.java:123)
    at com.mongodb.DBPort.go(DBPort.java:82)
    at com.mongodb.DBPort.call(DBPort.java:72)
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:202)
    at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:303)
    at com.mongodb.DB.command(DB.java:159)
    at com.mongodb.DBCollection.getStats(DBCollection.java:1038)
    at com.mongodb.hadoop.util.MongoSplitter.calculateSplits(MongoSplitter.java:52)
    at com.mongodb.hadoop.MongoInputFormat.getSplits(MongoInputFormat.java:51)
    at org.apache.hadoop.mapred.JobClient.writeNewSplits(JobClient.java:885)
    at org.apache.hadoop.mapred.JobClient.submitJobInternal(JobClient.java:779)
    at org.apache.hadoop.mapreduce.Job.submit(Job.java:432)
    at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:447)
    at  com.xxxx.extract.ExtractHadoop.get_data(ExtractHadoop.java:289)
    at  com.xxxx.extract.Extract.main(Extract.java:31)
com.mongodb.MongoException$Network: can't call something
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:211)
    at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:303)
    at com.mongodb.DB.command(DB.java:159)
    at com.mongodb.DBCollection.getStats(DBCollection.java:1038)
    at com.mongodb.hadoop.util.MongoSplitter.calculateSplits(MongoSplitter.java:52)
    at com.mongodb.hadoop.MongoInputFormat.getSplits(MongoInputFormat.java:51)
    at org.apache.hadoop.mapred.JobClient.writeNewSplits(JobClient.java:885)
    at org.apache.hadoop.mapred.JobClient.submitJobInternal(JobClient.java:779)
    at org.apache.hadoop.mapreduce.Job.submit(Job.java:432)
    at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:447)
    at com.xxxx.extract.ExtractHadoop.get_data(ExtractHadoop.java:289)
    at com.xxxx.extract.Extract.main(Extract.java:31)
Caused by: java.io.EOFException
    at org.bson.io.Bits.readFully(Bits.java:37)
    at org.bson.io.Bits.readFully(Bits.java:28)
    at com.mongodb.Response.<init>(Response.java:39)
    at com.mongodb.DBPort.go(DBPort.java:123)
    at com.mongodb.DBPort.go(DBPort.java:82)
    at com.mongodb.DBPort.call(DBPort.java:72)
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:202)
    ... 11 more

Would anyone be so kindly to explain me what I need to do to avoid this warning?

Thanks.

[Scott Hernandez]

You need to catch and handle the ioexception. I would suggest just
starting over if you get one. It probably means you had a socket
error.

> --
> 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.
> For more options, visit this group at
> http://groups.google.com/group/mongodb-user?hl=en.

[Martinus Martinus]

Hi Skot,

If I'm starting over it will be ok, but it will reach into that warning again after a few times.

Thanks.

[Scott Hernandez]

Any time that there is a network/socket error this can occur; it is
not something you can isolate to a specific time in the program.

On Tue, Jan 10, 2012 at 10:22 PM, Martinus Martinus

[Martinus Martinus]

Hi Skot,

I'm type in db.serverStatus() and this is what I got :

{
    "host" : "172.16.2.148",
    "version" : "2.0.1",
    "process" : "mongod",
    "uptime" : 60480,
    "uptimeEstimate" : 59986,
    "localTime" : ISODate("2012-01-12T02:19:03.018Z"),
    "globalLock" : {
        "totalTime" : 60479852232,
        "lockTime" : 51791,
        "ratio" : 8.563347642009828e-7,
        "currentQueue" : {
            "total" : 0,
            "readers" : 0,
            "writers" : 0
        },
        "activeClients" : {
            "total" : 0,
            "readers" : 0,
            "writers" : 0
        }
    },
    "mem" : {
        "bits" : 64,
        "resident" : 56,
        "virtual" : 9078,
        "supported" : true,
        "mapped" : 4127,
        "mappedWithJournal" : 8254
    },
    "connections" : {
        "current" : 655,
        "available" : 164
    },
    "extra_info" : {
        "note" : "fields vary by platform",
        "heap_usage_bytes" : 2803760,
        "page_faults" : 0
    },
    "indexCounters" : {
        "btree" : {
            "accesses" : 0,
            "hits" : 0,
            "misses" : 0,
            "resets" : 0,
            "missRatio" : 0
        }
    },
    "backgroundFlushing" : {
        "flushes" : 1007,
        "total_ms" : 59,
        "average_ms" : 0.05858987090367428,
        "last_ms" : 0,
        "last_finished" : ISODate("2012-01-12T02:18:03.245Z")
    },
    "cursors" : {
        "totalOpen" : 0,
        "clientCursors_size" : 0,
        "timedOut" : 0
    },
    "network" : {
        "bytesIn" : 8458533,
        "bytesOut" : 104107750,
        "numRequests" : 86087
    },
    "opcounters" : {
        "insert" : 0,
        "query" : 20820,
        "update" : 0,
        "delete" : 0,
        "getmore" : 0,
        "command" : 65269
    },
    "asserts" : {
        "regular" : 0,
        "warning" : 0,
        "msg" : 0,
        "user" : 0,
        "rollovers" : 0
    },
    "writeBacksQueued" : false,
    "dur" : {
        "commits" : 30,
        "journaledMB" : 0,
        "writeToDataFilesMB" : 0,
        "compression" : 0,
        "commitsInWriteLock" : 0,
        "earlyCommits" : 0,
        "timeMs" : {
            "dt" : 3067,
            "prepLogBuffer" : 0,
            "writeToJournal" : 0,
            "writeToDataFiles" : 0,
            "remapPrivateView" : 0
        }
    },
    "ok" : 1
}

And this is in my mongod log :

Thu Jan 12 02:13:04 [clientcursormon] mem (MB) res:56 virt:9075 mapped:4127
Thu Jan 12 02:13:56 [initandlisten] connection accepted from 172.16.4.148:34967 #1685
Thu Jan 12 02:15:23 [initandlisten] connection accepted from 172.16.4.148:44919 #1686
Thu Jan 12 02:17:35 [initandlisten] connection accepted from 172.16.4.148:44920 #1687
Thu Jan 12 02:18:04 [clientcursormon] mem (MB) res:56 virt:9078 mapped:4127
Thu Jan 12 02:19:04 [initandlisten] connection accepted from 172.16.4.148:44922 #1688
Thu Jan 12 02:21:24 [initandlisten] connection accepted from 172.16.4.148:56921 #1689

Is it normal to have this many connections coming from many different port?

Thanks.

[Scott Hernandez]

Yes, the operating system (tcp stack) will use a set of ports to
connect from; that is expected and defined by the tcp specification.

http://en.wikipedia.org/wiki/Ephemeral_port

On Wed, Jan 11, 2012 at 6:23 PM, Martinus Martinus

[Martinus Martinus]

Hi Skot,

I have 4 hadoop clusters and when I run the map/reduce job for one time it will generate 4 connection accepted message from 4 different ports and also 4 end connections message on mongod log. But if I run the map/reduce job in a continuous while loop that doing the same map/reduce job, it will keep generate 4 connections accepted message from 4 different ports in mongod log every time with each new connections will have 4 different ports as well and the current connection information on db.serverStatus() will keep increasing all the time :

  "connections" : {
        "current" : 655,
        "available" : 164
    },

and when it reached "available" : 0, then it will generated this warning message on eclipse console :

Conf: Configuration: core-default.xml, core-site.xml, mapred-default.xml, mapred-site.xml

12/01/12 11:53:35 WARN mapred.JobClient: No job jar file set.  User classes may not be found. See JobConf(Class) or JobConf#setJar(String).
Jan 12, 2012 11:53:35 AM com.mongodb.DBTCPConnector fetchMaxBsonObjectSize

WARNING: Exception determining maxBSON size using0
java.io.EOFException

    at org.bson.io.Bits.readFully(Bits.java:37)
    at org.bson.io.Bits.readFully(Bits.java:28)
    at com.mongodb.Response.<init>(Response.java:39)
    at com.mongodb.DBPort.go(DBPort.java:123)
    at com.mongodb.DBPort.go(DBPort.java:82)

    at com.mongodb.DBPort.findOne(DBPort.java:142)
    at com.mongodb.DBPort.runCommand(DBPort.java:151)
    at com.mongodb.DBTCPConnector.fetchMaxBsonObjectSize(DBTCPConnector.java:429)
    at com.mongodb.DBTCPConnector.checkMaster(DBTCPConnector.java:416)
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:193)
    at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:303)
    at com.mongodb.DB.command(DB.java:159)
    at com.mongodb.DBCollection.getStats(DBCollection.java:1038)
    at com.mongodb.hadoop.util.MongoSplitter.calculateSplits(MongoSplitter.java:52)
    at com.mongodb.hadoop.MongoInputFormat.getSplits(MongoInputFormat.java:51)
    at org.apache.hadoop.mapred.JobClient.writeNewSplits(JobClient.java:885)
    at org.apache.hadoop.mapred.JobClient.submitJobInternal(JobClient.java:779)
    at org.apache.hadoop.mapreduce.Job.submit(Job.java:432)
    at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:447)

    at com.digbil.hdextract.Extract.get_data(Extract.java:294)
    at com.digbil.hdextract.HadoopExtract.main(HadoopExtract.java:31)
Jan 12, 2012 11:53:35 AM com.mongodb.DBPortPool gotError
WARNING: emptying DBPortPool to 172.16.2.146:27017 b/c of error

java.io.EOFException
    at org.bson.io.Bits.readFully(Bits.java:37)
    at org.bson.io.Bits.readFully(Bits.java:28)
    at com.mongodb.Response.<init>(Response.java:39)
    at com.mongodb.DBPort.go(DBPort.java:123)
    at com.mongodb.DBPort.go(DBPort.java:82)
    at com.mongodb.DBPort.call(DBPort.java:72)
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:202)
    at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:303)
    at com.mongodb.DB.command(DB.java:159)
    at com.mongodb.DBCollection.getStats(DBCollection.java:1038)
    at com.mongodb.hadoop.util.MongoSplitter.calculateSplits(MongoSplitter.java:52)
    at com.mongodb.hadoop.MongoInputFormat.getSplits(MongoInputFormat.java:51)
    at org.apache.hadoop.mapred.JobClient.writeNewSplits(JobClient.java:885)
    at org.apache.hadoop.mapred.JobClient.submitJobInternal(JobClient.java:779)
    at org.apache.hadoop.mapreduce.Job.submit(Job.java:432)
    at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:447)

    at com.digbil.hdextract.Extract.get_data(Extract.java:294)
    at com.digbil.hdextract.HadoopExtract.main(HadoopExtract.java:31)

com.mongodb.MongoException$Network: can't call something
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:211)
    at com.mongodb.DBApiLayer$MyCollection.__find(DBApiLayer.java:303)
    at com.mongodb.DB.command(DB.java:159)
    at com.mongodb.DBCollection.getStats(DBCollection.java:1038)
    at com.mongodb.hadoop.util.MongoSplitter.calculateSplits(MongoSplitter.java:52)
    at com.mongodb.hadoop.MongoInputFormat.getSplits(MongoInputFormat.java:51)
    at org.apache.hadoop.mapred.JobClient.writeNewSplits(JobClient.java:885)
    at org.apache.hadoop.mapred.JobClient.submitJobInternal(JobClient.java:779)
    at org.apache.hadoop.mapreduce.Job.submit(Job.java:432)
    at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:447)

    at com.digbil.hdextract.Extract.get_data(Extract.java:294)
    at com.digbil.hdextract.HadoopExtract.main(HadoopExtract.java:31)

Caused by: java.io.EOFException
    at org.bson.io.Bits.readFully(Bits.java:37)
    at org.bson.io.Bits.readFully(Bits.java:28)
    at com.mongodb.Response.<init>(Response.java:39)
    at com.mongodb.DBPort.go(DBPort.java:123)
    at com.mongodb.DBPort.go(DBPort.java:82)
    at com.mongodb.DBPort.call(DBPort.java:72)
    at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:202)
    ... 11 more

And on my mongod log it's now become like this :

Wed Jan 11 06:04:25 [initandlisten] connection refused because too many open connections: 819
Wed Jan 11 06:04:38 [initandlisten] connection accepted from 172.16.4.147:54581 #10857
Wed Jan 11 06:04:38 [initandlisten] connection refused because too many open connections: 819
Wed Jan 11 06:04:38 [initandlisten] connection accepted from 172.16.4.147:54582 #10858
Wed Jan 11 06:04:38 [initandlisten] connection refused because too many open connections: 819
Wed Jan 11 06:08:45 [clientcursormon] mem (MB) res:42 virt:9275 mapped:4127
...
Thu Jan 12 03:54:12 [conn1961] end connection 172.16.4.147:54541
Thu Jan 12 03:54:12 [conn1962] end connection 172.16.4.147:54542
Thu Jan 12 03:54:12 [conn1963] end connection 172.16.4.147:54543
Thu Jan 12 03:54:12 [conn1964] end connection 172.16.4.147:54544
Thu Jan 12 03:54:12 [conn1965] end connection 172.16.4.147:54545
Thu Jan 12 03:54:12 [conn1966] end connection 172.16.4.147:54546
Thu Jan 12 03:54:12 [conn1967] end connection 172.16.4.147:54547
Thu Jan 12 03:54:12 [conn1968] end connection 172.16.4.147:54548
Thu Jan 12 03:54:12 [conn1969] end connection 172.16.4.147:54549
Thu Jan 12 03:54:12 [conn1970] end connection 172.16.4.147:54550
Thu Jan 12 03:54:12 [conn1971] end connection 172.16.4.147:54551
Thu Jan 12 03:54:12 [conn1972] end connection 172.16.4.147:54552
Thu Jan 12 03:54:12 [conn1973] end connection 172.16.4.147:54553
Thu Jan 12 03:54:12 [conn1974] end connection 172.16.4.147:54554
Thu Jan 12 03:54:12 [conn1975] end connection 172.16.4.147:54555
Thu Jan 12 03:54:12 [conn1976] end connection 172.16.4.147:54556
Thu Jan 12 03:54:12 [conn1977] end connection 172.16.4.147:54557
Thu Jan 12 03:54:12 [conn1978] end connection 172.16.4.147:54558
Thu Jan 12 03:54:12 [conn1979] end connection 172.16.4.147:54559
Thu Jan 12 03:54:12 [conn1980] end connection 172.16.4.147:54560
Thu Jan 12 03:54:12 [conn1981] end connection 172.16.4.147:54561
Thu Jan 12 03:54:12 [conn1982] end connection 172.16.4.147:54562
Thu Jan 12 03:54:12 [conn1983] end connection 172.16.4.147:54563
Thu Jan 12 03:54:12 [conn1984] end connection 172.16.4.147:54564
Thu Jan 12 03:54:12 [conn1985] end connection 172.16.4.147:54565
Thu Jan 12 03:54:12 [conn1986] end connection 172.16.4.147:54566
Thu Jan 12 03:54:12 [conn1987] end connection 172.16.4.147:54567
Thu Jan 12 03:54:12 [conn1988] end connection 172.16.4.147:54568
Thu Jan 12 03:54:12 [conn1989] end connection 172.16.4.147:54569
Thu Jan 12 03:54:12 [conn1990] end connection 172.16.4.147:54570
Thu Jan 12 03:54:12 [conn1991] end connection 172.16.4.147:54572
Thu Jan 12 03:54:12 [conn1992] end connection 172.16.4.147:54573
Thu Jan 12 03:54:12 [conn1993] end connection 172.16.4.147:54574
Thu Jan 12 03:54:12 [conn1994] end connection 172.16.4.147:54575
Thu Jan 12 03:54:12 [conn1995] end connection 172.16.4.147:54576
Thu Jan 12 03:54:12 [conn1996] end connection 172.16.4.147:54577
Thu Jan 12 03:54:12 [conn1997] end connection 172.16.4.147:54578
Thu Jan 12 03:54:12 [conn1998] end connection 172.16.4.147:54579
Thu Jan 12 03:54:12 [conn1999] end connection 172.16.4.147:54580
and many more.

Thanks.

[Scott Hernandez]

The mongodb java driver uses a connection pool per Mongo instance so
if multiple instances are created and used you would get this kind of
connection behavior.

How have you configured the plugin? Also, what version are you using?

On Wed, Jan 11, 2012 at 8:02 PM, Martinus Martinus

[Martinus Martinus]

Hi Skot,

I used the mongo-hadoop plugin from https://github.com/mongodb/mongo-hadoop and my MongoDB version is 2.0.1 64 bit for linux.

Thanks.

[Scott Hernandez]

What does your config file look like for the hadoop plugin? Are you
creating any Mongo instances manually? Are you using this for input or
output?

The getCollection helper will create a singleton Mongo instance so it
shouldn't be creating multiple instances:
https://github.com/mongodb/mongo-hadoop/blob/master/core/src/main/java/com/mongodb/hadoop/util/MongoConfigUtil.java#L257

On Wed, Jan 11, 2012 at 10:22 PM, Martinus Martinus

[Martinus Martinus]

Hi Scott,

This is my config looks like :

http://pastie.org/3170819

I called this class from the main function :

public class HadoopExtract {

    /**
     * @param args
     */
   
    public static void main(String[] args) throws Exception{
        // TODO Auto-generated method stub
        Mongo m = new Mongo("172.16.2.146", 27017);
       
        DB db = m.getDB("test");
       
        while(true)
        {
            Extract insert_checked = new Extract();
            insert_checked.get_data(db, m);
        }
    }
}

Thanks.

[Scott Hernandez]

It looks like you should move all the stuff before the try in
Extract.get_data to the constructor.

See if that changes the connection behavior.

It also seems like you have provided incomplete code since the call
below is different than the method signature of get_data in the
pastie..

On Wed, Jan 11, 2012 at 11:06 PM, Martinus Martinus

[Martinus Martinus]

Hi Scott,

I have made changed like you suggest :

http://pastie.org/3170819

and called it using this main :

public class HadoopExtract {

    /**
     * @param args
     */
   
    public static void main(String[] args) throws Exception{
        // TODO Auto-generated method stub
       

        while(true)
        {
            Extract insert_checked = new Extract();

            insert_checked.get_data();
        }
    }
}

But it still gave me many connections as before.

Thanks.

[Nat]

Can you get lsof output from each hadoop box when the connection is high?

[Martinus Martinus]

Hi Nat,

You mean from each hadoop node? And what type of command should I type? only lsof or lsof | grep TCP ?

Thanks.

On Fri, Jan 13, 2012 at 11:29 AM, Nat <nat....@gmail.com> wrote:

Can you get lsof output from each hadoop box when the connection is high?

--

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

To view this discussion on the web visit https://groups.google.com/d/msg/mongodb-user/-/DYEumknXbhQJ.

[Nat]

Yes. How many connections are you talking about? Can you list down your data stats as well?

---

From: Martinus Martinus <marti...@gmail.com>

Sender: mongod...@googlegroups.com

Date: Fri, 13 Jan 2012 11:37:28 +0800

To: <mongod...@googlegroups.com>

ReplyTo: mongod...@googlegroups.com

Subject: Re: [mongodb-user] warning when running on continuous while loop

[Brendan McAdams]

Every hadoop worker and the job config client process are going to spin up their own connection pool. The client calculates split ranges but the actual reads out of Mongo happen on your Hadoop nodes. 

-b

[Martinus Martinus]

Hi Nat,

This is from my mongod log :

Fri Jan 13 03:56:31 [conn3181] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:31 [conn3181] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:32 [initandlisten] connection accepted from 172.16.4.147:60498 #3570
Fri Jan 13 03:56:32 [initandlisten] connection accepted from 172.16.4.147:60499 #3571
Fri Jan 13 03:56:33 [initandlisten] connection accepted from 172.16.4.147:60500 #3572
Fri Jan 13 03:56:33 [conn3184] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:33 [conn3184] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:33 [conn3184] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:33 [initandlisten] connection accepted from 172.16.4.147:60501 #3573
Fri Jan 13 03:56:34 [initandlisten] connection accepted from 172.16.4.147:60502 #3574
Fri Jan 13 03:56:34 [initandlisten] connection accepted from 172.16.4.147:60503 #3575
Fri Jan 13 03:56:34 [conn3187] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:34 [conn3187] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:35 [initandlisten] connection accepted from 172.16.4.147:60504 #3576
Fri Jan 13 03:56:35 [initandlisten] connection accepted from 172.16.4.147:60505 #3577
Fri Jan 13 03:56:35 [initandlisten] connection accepted from 172.16.4.147:60506 #3578
Fri Jan 13 03:56:36 [conn3190] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:36 [conn3190] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:36 [initandlisten] connection accepted from 172.16.4.147:60507 #3579
Fri Jan 13 03:56:36 [initandlisten] connection accepted from 172.16.4.147:60508 #3580
Fri Jan 13 03:56:37 [initandlisten] connection accepted from 172.16.4.147:60509 #3581
Fri Jan 13 03:56:37 [conn3193] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:37 [conn3193] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:37 [initandlisten] connection accepted from 172.16.4.147:60510 #3582
Fri Jan 13 03:56:37 [initandlisten] connection accepted from 172.16.4.147:60511 #3583
Fri Jan 13 03:56:38 [initandlisten] connection accepted from 172.16.4.147:60512 #3584
Fri Jan 13 03:56:38 [conn3196] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:38 [conn3196] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:38 [conn3196] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:39 [initandlisten] connection accepted from 172.16.4.147:60513 #3585
Fri Jan 13 03:56:39 [initandlisten] connection accepted from 172.16.4.147:60514 #3586
Fri Jan 13 03:56:39 [initandlisten] connection accepted from 172.16.4.147:60515 #3587
Fri Jan 13 03:56:39 [conn3199] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:40 [conn3199] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:40 [initandlisten] connection accepted from 172.16.4.147:60516 #3588
Fri Jan 13 03:56:40 [initandlisten] connection accepted from 172.16.4.147:60517 #3589
Fri Jan 13 03:56:40 [initandlisten] connection accepted from 172.16.4.147:60518 #3590
Fri Jan 13 03:56:40 [conn3202] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:41 [conn3202] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:41 [initandlisten] connection accepted from 172.16.4.147:60519 #3591
Fri Jan 13 03:56:41 [initandlisten] connection accepted from 172.16.4.147:60520 #3592
Fri Jan 13 03:56:41 [initandlisten] connection accepted from 172.16.4.147:60521 #3593
Fri Jan 13 03:56:42 [conn3205] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:42 [conn3205] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:42 [conn3205] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:42 [initandlisten] connection accepted from 172.16.4.147:60522 #3594
Fri Jan 13 03:56:42 [initandlisten] connection accepted from 172.16.4.147:60523 #3595
Fri Jan 13 03:56:43 [initandlisten] connection accepted from 172.16.4.147:60524 #3596
Fri Jan 13 03:56:43 [conn3208] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2

This is after I terminate program :

Fri Jan 13 03:56:43 [conn3179] end connection 172.16.4.147:60495
Fri Jan 13 03:56:43 [conn3180] end connection 172.16.4.147:60496
Fri Jan 13 03:56:43 [conn3181] end connection 172.16.4.147:60497
Fri Jan 13 03:56:43 [conn3182] end connection 172.16.4.147:60498
Fri Jan 13 03:56:43 [conn3183] end connection 172.16.4.147:60499
Fri Jan 13 03:56:43 [conn3184] end connection 172.16.4.147:60500
Fri Jan 13 03:56:43 [conn3185] end connection 172.16.4.147:60501
Fri Jan 13 03:56:43 [conn3186] end connection 172.16.4.147:60502
Fri Jan 13 03:56:43 [conn3187] end connection 172.16.4.147:60503
Fri Jan 13 03:56:43 [conn3188] end connection 172.16.4.147:60504
Fri Jan 13 03:56:43 [conn3189] end connection 172.16.4.147:60505
Fri Jan 13 03:56:43 [conn3190] end connection 172.16.4.147:60506
Fri Jan 13 03:56:43 [conn3191] end connection 172.16.4.147:60507
Fri Jan 13 03:56:43 [conn3192] end connection 172.16.4.147:60508
Fri Jan 13 03:56:43 [conn3193] end connection 172.16.4.147:60509
Fri Jan 13 03:56:43 [conn3194] end connection 172.16.4.147:60510
Fri Jan 13 03:56:43 [conn3195] end connection 172.16.4.147:60511
Fri Jan 13 03:56:43 [conn3196] end connection 172.16.4.147:60512
Fri Jan 13 03:56:43 [conn3197] end connection 172.16.4.147:60513
Fri Jan 13 03:56:43 [conn3198] end connection 172.16.4.147:60514
Fri Jan 13 03:56:43 [conn3200] end connection 172.16.4.147:60516
Fri Jan 13 03:56:43 [conn3201] end connection 172.16.4.147:60517
Fri Jan 13 03:56:43 [conn3202] end connection 172.16.4.147:60518
Fri Jan 13 03:56:43 [conn3203] end connection 172.16.4.147:60519
Fri Jan 13 03:56:43 [conn3204] end connection 172.16.4.147:60520
Fri Jan 13 03:56:43 [conn3205] end connection 172.16.4.147:60521
Fri Jan 13 03:56:43 [conn3206] end connection 172.16.4.147:60522
Fri Jan 13 03:56:43 [conn3207] end connection 172.16.4.147:60523
Fri Jan 13 03:56:43 [conn3199] end connection 172.16.4.147:60515
Fri Jan 13 03:56:43 [conn3208] end connection 172.16.4.147:60524

The connections is growing up until there is no available connections left on the mongod.

Thanks.

[Martinus Martinus]

Hi Brendan,

So how to make my above while loop code to keep using the same port number and didn't generate the new one? Because my code purpose is actually to keep querying data if there is a new document coming into the collections and calculate the data and put back into the collection again.

Thanks.

[Brendan McAdams]

On the workers it will spin up a new job and new set of ports with each job you spin up; I'm uncertain. Keep in mind that Hadoop isn't really designed for real time processing which is what it seems you're trying to accomplish. Also, we don't do any kind of merging of existing data if you write to a collection with existing data in it. 

-b

On 12 Jan 2012, at 23:03, Martinus Martinus <marti...@gmail.com> wrote:

Hi Brendan,

So how to make my above while loop code to keep using the same port number and didn't generate the new one? Because my code purpose is actually to keep querying data if there is a new document coming into the collections and calculate the data and put back into the collection again.

Thanks.

On Fri, Jan 13, 2012 at 12:00 PM, Martinus Martinus <marti...@gmail.com> wrote:

Hi Nat,

This is from my mongod log :

Fri Jan 13 03:56:31 [conn3181] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:31 [conn3181] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test2.output2
Fri Jan 13 03:56:32 [initandlisten] connection accepted from 172.16.4.147:60498 #3570
Fri Jan 13 03:56:32 [initandlisten] connection accepted from 172.16.4.147:60499 #3571

Fri Jan 13 03:56:33 [initandlisten] connection accepted from 172.16.4.147:o60500 #3572

[Martinus Martinus]

Hi Brendan,

Thanks for your explanation. So is there any other way to make one new job and end the connection for each call and open and closed a new connection again for the new job?

And how to make sure that all of my hadoop clusters available is actually working on the map/reduce job?

Thanks.

[Martinus Martinus]

Hi,

I tried to make the main looks like this :

public class HadoopExtract {

    /**
     * @param args
     */


 public static void main(String[] args) throws Exception{
        // TODO Auto-generated method stub
       

        Configuration conf = new Configuration();
        MongoConfigUtil.setInputURI(conf, "mongodb://172.16.2.146/test.input");
        MongoConfigUtil.setOutputURI(conf, "mongodb://172.16.2.146/test2.output");

        job = new Job(conf, "word count");

        while(true)
        {
            Extract insert_checked = new Extract();

            insert_checked.get_data(conf, job);
        }
    }
}

But it gave me warning like this :

java.lang.IllegalStateException: Job in state RUNNING instead of DEFINE
    at org.apache.hadoop.mapreduce.Job.ensureState(Job.java:60)
    at org.apache.hadoop.mapreduce.Job.setMapperClass(Job.java:115)
    at com.digbil.hdextract.insert_checked.get_data(insert_checked.java:301)
    at com.digbil.hdextract.HadoopExtract.main(HadoopExtract.java:42)

How to make the job only running on certain port numbers over and over again until I terminate the program or close and open the connection for each job?

Thanks.

[Brendan McAdams]

This is really beyond what, to the best of my knowledge, Hadoop is designed for. 

Once again, it is not intended for continuous running aka "real time" processing. 

-b

[Martinus Martinus]

Hi Brendan,

Thanks for your explanation. But is there another way to close all open connections after we finished with one map/reduce job without using System.exit()?

Thanks.

[Nat]

How many child processes do you have? If it's not too much of a problem, increasing the total available connections of mongod is a good workaround for the moment.

[Martinus Martinus]

Hi Nat,

Yes, that can be a good solution. But after a long time, the connection available will become depleted and empty and it will generate warning about refused connection because too many open connections.

Thanks.

On Tue, Jan 17, 2012 at 1:16 PM, Nat <nat....@gmail.com> wrote:

How many child processes do you have? If it's not too much of a problem, increasing the total available connections of mongod is a good workaround for the moment.

--

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

To view this discussion on the web visit https://groups.google.com/d/msg/mongodb-user/-/MJnX7BZZs_IJ.

[Martinus Martinus]

Hi Nat,

O by the way, how can I know if the work is actually distributed or not in this hadoop-mongo setup? Because I have one master node act as master and slave and three other slave nodes, but I don't see any open connection coming into the mongod server log that has ip addresses from the slave machines.

Thanks.

[Nat]

Check lsof. You should see how many connections are used for each process and how many processes are there. Try to run your job multiple times and see how many processes there are and whether it increases or not.

---

From: Martinus Martinus <marti...@gmail.com>

Sender: mongod...@googlegroups.com

Date: Tue, 17 Jan 2012 14:21:12 +0800

To: <mongod...@googlegroups.com>

ReplyTo: mongod...@googlegroups.com

Subject: Re: [mongodb-user] warning when running on continuous while loop

[Martinus Martinus]

Hi Nat,

I have checked it and it always increases all the time, because on the mongod log it always displayed that it's has connection accepted from 172.16.2.147:44561 and all of this connection will not be closed until I terminate the program.

And it's all of my hadoop nodes are running? Because it's print out like this on Mongod log :

Wed Jan 11 09:49:26 [conn41] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test.rest
Wed Jan 11 09:49:27 [initandlisten] connection accepted from 172.16.4.147:59109 #87
Wed Jan 11 09:49:37 [initandlisten] connection accepted from 172.16.4.147:56643 #88
Wed Jan 11 09:49:45 [conn41] info DFM::findAll(): extent 0:12000 was empty, skipping ahead. ns:test.rest
Wed Jan 11 09:49:51 [initandlisten] connection accepted from 172.16.4.147:56645 #89
Wed Jan 11 09:50:03 [initandlisten] connection accepted from 172.16.4.147:56646 #90

It seem's like all connections always come only from the master node ip address with different port numbers. Is that should be the right mongod log that we should receive when using mongo-hadoop with 4 nodes?

Thanks.

[Nat]

Can you get the result of lsof/ps after running each hadoop job?

---

From: Martinus Martinus <marti...@gmail.com>

Sender: mongod...@googlegroups.com

Date: Tue, 17 Jan 2012 15:23:46 +0800

[Martinus Martinus]

Hi Nat,

This is the result when I typed in on my master :

http://pastie.org/3200254

and this is the result from each of my slaves nodes :

http://pastie.org/3200210
http://pastie.org/3200225
http://pastie.org/3200237

Thanks.

[Nat]

Sorry.... it should be "lsof -i"

[Martinus Martinus]

Hi Nat,

This is for lsof -i in master :

http://pastie.org/3206039

and this is on every slaves node :

- http://pastie.org/3206024
- http://pastie.org/3206030
- http://pastie.org/3206034

Thanks.

On Tue, Jan 17, 2012 at 8:24 PM, Nat <nat....@gmail.com> wrote:

Sorry.... it should be "lsof -i"

--

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

To view this discussion on the web visit https://groups.google.com/d/msg/mongodb-user/-/V_HALhFnYlkJ.

[Martinus Martinus]

Hi Brendan/Nat,

How can I get the mongo instances that one job is using to connect to MongoDB database?

Thanks.

[Nat]

Based on lsof, it looks like all connections came from the same process. Would you mind to send me the project? I can take a look how it happens in case that there is something with your code/config.

---

From: Martinus Martinus <marti...@gmail.com>

Sender: mongod...@googlegroups.com

Date: Thu, 19 Jan 2012 16:36:21 +0800

To: <mongod...@googlegroups.com>

ReplyTo: mongod...@googlegroups.com

Subject: Re: [mongodb-user] warning when running on continuous while loop

[Martinus Martinus]

Hi Nat,

Ok, no problem. I have sent it.

Thanks.