The map/reduce job finished.
The input table has ~ 50 million records with row key in form
(TYPE|VALUE|ID), the output table held row key (TYPE|VALUE) with a single
column family which held a value of count (the # of IDs in TYPE|VALUE).
Here is the output for the job:
09/06/24 09:10:44 INFO mapred.JobClient: Running job: job_200906240907_0001
09/06/24 09:10:45 INFO mapred.JobClient: map 0% reduce 0%
09/06/24 09:11:19 WARN zookeeper.ClientCnxn: Exception closing session
0x12212fd59fe000f to sun.nio.ch.selectionkeyi...@654df764
java.io.IOException: TIMED OUT
at
org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:858)
09/06/24 09:11:21 INFO zookeeper.ClientCnxn: Attempting connection to server
server55/192.168.0.55:2181
09/06/24 09:11:21 INFO zookeeper.ClientCnxn: Priming connection to
java.nio.channels.SocketChannel[connected local=/192.168.0.55:59551
remote=server55/192.168.0.55:2181]
09/06/24 09:11:21 INFO zookeeper.ClientCnxn: Server connection successful
09/06/24 09:11:28 WARN zookeeper.ClientCnxn: Exception closing session
0x12212fd59fe000f to sun.nio.ch.selectionkeyi...@74c6eff5
java.io.IOException: TIMED OUT
at
org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:858)
09/06/24 09:11:29 INFO zookeeper.ClientCnxn: Attempting connection to server
server55/192.168.0.55:2181
09/06/24 09:11:29 INFO zookeeper.ClientCnxn: Priming connection to
java.nio.channels.SocketChannel[connected local=/192.168.0.55:59558
remote=server55/192.168.0.55:2181]
09/06/24 09:11:29 INFO zookeeper.ClientCnxn: Server connection successful
09/06/24 09:11:36 WARN zookeeper.ClientCnxn: Exception closing session
0x12212fd59fe000f to sun.nio.ch.selectionkeyi...@5567d7fb
java.io.IOException: TIMED OUT
at
org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:858)
09/06/24 09:11:38 INFO zookeeper.ClientCnxn: Attempting connection to server
server55/192.168.0.55:2181
09/06/24 09:11:38 INFO zookeeper.ClientCnxn: Priming connection to
java.nio.channels.SocketChannel[connected local=/192.168.0.55:59571
remote=server55/192.168.0.55:2181]
09/06/24 09:11:38 INFO zookeeper.ClientCnxn: Server connection successful
09/06/24 09:11:51 WARN zookeeper.ClientCnxn: Exception closing session
0x12212fd59fe000f to sun.nio.ch.selectionkeyi...@51701bdc
java.io.IOException: TIMED OUT
at
org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:858)
09/06/24 09:11:52 INFO zookeeper.ClientCnxn: Attempting connection to server
server55/192.168.0.55:2181
09/06/24 09:11:52 INFO zookeeper.ClientCnxn: Priming connection to
java.nio.channels.SocketChannel[connected local=/192.168.0.55:59575
remote=server55/192.168.0.55:2181]
09/06/24 09:11:52 INFO zookeeper.ClientCnxn: Server connection successful
09/06/24 09:25:15 INFO mapred.JobClient: map 3% reduce 0%
09/06/24 09:27:13 INFO mapred.JobClient: map 7% reduce 0%
09/06/24 09:27:32 INFO mapred.JobClient: map 7% reduce 1%
09/06/24 09:28:17 INFO mapred.JobClient: map 7% reduce 2%
09/06/24 09:28:35 INFO mapred.JobClient: map 10% reduce 2%
09/06/24 09:28:48 INFO mapred.JobClient: map 10% reduce 3%
09/06/24 09:31:30 INFO mapred.JobClient: map 14% reduce 3%
09/06/24 09:31:40 INFO mapred.JobClient: map 14% reduce 4%
09/06/24 09:39:54 INFO mapred.JobClient: map 17% reduce 4%
09/06/24 09:40:03 INFO mapred.JobClient: map 17% reduce 5%
09/06/24 09:42:12 INFO mapred.JobClient: map 25% reduce 5%
09/06/24 09:42:21 INFO mapred.JobClient: map 25% reduce 6%
09/06/24 09:42:23 INFO mapred.JobClient: map 25% reduce 7%
09/06/24 09:42:25 INFO mapred.JobClient: map 25% reduce 8%
09/06/24 09:42:52 INFO mapred.JobClient: map 28% reduce 8%
09/06/24 09:43:04 INFO mapred.JobClient: map 28% reduce 9%
09/06/24 09:43:10 INFO mapred.JobClient: map 32% reduce 9%
09/06/24 09:43:21 INFO mapred.JobClient: map 32% reduce 10%
09/06/24 09:48:43 INFO mapred.JobClient: map 35% reduce 10%
09/06/24 09:48:49 INFO mapred.JobClient: map 35% reduce 11%
09/06/24 09:51:34 INFO mapred.JobClient: map 39% reduce 11%
09/06/24 09:51:43 INFO mapred.JobClient: map 39% reduce 12%
09/06/24 09:51:46 INFO mapred.JobClient: map 39% reduce 13%
09/06/24 09:54:56 INFO mapred.JobClient: map 42% reduce 13%
09/06/24 09:54:59 INFO mapred.JobClient: map 46% reduce 13%
09/06/24 09:55:05 INFO mapred.JobClient: map 46% reduce 15%
09/06/24 09:57:42 INFO mapred.JobClient: map 50% reduce 15%
09/06/24 09:57:54 INFO mapred.JobClient: map 50% reduce 16%
09/06/24 09:59:03 INFO mapred.JobClient: map 53% reduce 16%
09/06/24 09:59:14 INFO mapred.JobClient: map 53% reduce 17%
09/06/24 10:04:46 INFO mapred.JobClient: map 57% reduce 17%
09/06/24 10:04:51 INFO mapred.JobClient: map 57% reduce 18%
09/06/24 10:04:58 INFO mapred.JobClient: map 57% reduce 19%
09/06/24 10:06:00 INFO mapred.JobClient: map 60% reduce 19%
09/06/24 10:06:13 INFO mapred.JobClient: map 60% reduce 20%
09/06/24 10:06:29 INFO mapred.JobClient: map 64% reduce 20%
09/06/24 10:06:43 INFO mapred.JobClient: map 64% reduce 21%
09/06/24 10:08:07 INFO mapred.JobClient: map 67% reduce 21%
09/06/24 10:08:16 INFO mapred.JobClient: map 67% reduce 22%
09/06/24 10:10:24 INFO mapred.JobClient: map 71% reduce 22%
09/06/24 10:10:30 INFO mapred.JobClient: map 71% reduce 23%
09/06/24 10:10:40 INFO mapred.JobClient: map 74% reduce 23%
09/06/24 10:10:43 INFO mapred.JobClient: map 74% reduce 24%
09/06/24 10:14:17 INFO mapred.JobClient: map 78% reduce 24%
09/06/24 10:14:21 INFO mapred.JobClient: map 78% reduce 25%
09/06/24 10:14:28 INFO mapred.JobClient: map 78% reduce 26%
09/06/24 10:15:30 INFO mapred.JobClient: map 82% reduce 26%
09/06/24 10:15:41 INFO mapred.JobClient: map 82% reduce 27%
09/06/24 10:17:43 INFO mapred.JobClient: map 85% reduce 27%
09/06/24 10:17:52 INFO mapred.JobClient: map 85% reduce 28%
09/06/24 10:25:20 INFO mapred.JobClient: map 89% reduce 28%
09/06/24 10:25:31 INFO mapred.JobClient: map 89% reduce 29%
09/06/24 10:25:58 INFO mapred.JobClient: map 92% reduce 29%
09/06/24 10:26:06 INFO mapred.JobClient: map 92% reduce 30%
09/06/24 10:29:52 INFO mapred.JobClient: map 96% reduce 30%
09/06/24 10:30:00 INFO mapred.JobClient: map 96% reduce 31%
09/06/24 10:30:04 INFO mapred.JobClient: map 96% reduce 32%
09/06/24 10:32:04 INFO mapred.JobClient: map 100% reduce 32%
09/06/24 10:32:16 INFO mapred.JobClient: map 100% reduce 33%
09/06/24 10:32:24 INFO mapred.JobClient: map 100% reduce 39%
09/06/24 10:32:26 INFO mapred.JobClient: map 100% reduce 45%
09/06/24 10:32:28 INFO mapred.JobClient: map 100% reduce 51%
09/06/24 10:32:29 INFO mapred.JobClient: map 100% reduce 57%
09/06/24 10:32:32 INFO mapred.JobClient: map 100% reduce 69%
09/06/24 10:32:35 INFO mapred.JobClient: map 100% reduce 70%
09/06/24 10:32:38 INFO mapred.JobClient: map 100% reduce 71%
09/06/24 10:32:49 INFO mapred.JobClient: map 100% reduce 72%
09/06/24 10:32:56 INFO mapred.JobClient: map 100% reduce 74%
09/06/24 10:32:58 INFO mapred.JobClient: map 100% reduce 75%
09/06/24 10:33:10 INFO mapred.JobClient: map 100% reduce 76%
09/06/24 10:33:20 INFO mapred.JobClient: map 100% reduce 77%
09/06/24 10:33:31 INFO mapred.JobClient: map 100% reduce 78%
09/06/24 10:34:06 INFO mapred.JobClient: map 100% reduce 79%
09/06/24 10:34:21 INFO mapred.JobClient: map 100% reduce 80%
09/06/24 10:34:25 INFO mapred.JobClient: map 100% reduce 82%
09/06/24 10:34:27 INFO mapred.JobClient: map 100% reduce 83%
09/06/24 10:34:36 INFO mapred.JobClient: map 100% reduce 84%
09/06/24 10:34:37 INFO mapred.JobClient: map 100% reduce 85%
09/06/24 10:34:57 INFO mapred.JobClient: map 100% reduce 86%
09/06/24 10:35:43 INFO mapred.JobClient: map 100% reduce 87%
09/06/24 10:36:29 INFO mapred.JobClient: map 100% reduce 88%
09/06/24 10:37:02 INFO mapred.JobClient: map 100% reduce 89%
09/06/24 10:37:10 INFO mapred.JobClient: map 100% reduce 90%
09/06/24 10:37:19 INFO mapred.JobClient: map 100% reduce 91%
09/06/24 10:37:24 INFO mapred.JobClient: map 100% reduce 92%
09/06/24 10:37:27 INFO mapred.JobClient: map 100% reduce 93%
09/06/24 10:37:30 INFO mapred.JobClient: map 100% reduce 94%
09/06/24 10:37:36 INFO mapred.JobClient: map 100% reduce 95%
09/06/24 10:37:39 INFO mapred.JobClient: map 100% reduce 96%
09/06/24 10:37:41 INFO mapred.JobClient: map 100% reduce 97%
09/06/24 10:37:43 INFO mapred.JobClient: map 100% reduce 98%
09/06/24 10:37:44 INFO mapred.JobClient: map 100% reduce 100%
09/06/24 10:37:46 INFO mapred.JobClient: Job complete: job_200906240907_0001
09/06/24 10:37:46 INFO mapred.JobClient: Counters: 17
09/06/24 10:37:46 INFO mapred.JobClient: Job Counters
09/06/24 10:37:46 INFO mapred.JobClient: Launched reduce tasks=8
09/06/24 10:37:46 INFO mapred.JobClient: Rack-local map tasks=9
09/06/24 10:37:46 INFO mapred.JobClient: Launched map tasks=35
09/06/24 10:37:46 INFO mapred.JobClient: Data-local map tasks=26
09/06/24 10:37:46 INFO mapred.JobClient: FileSystemCounters
09/06/24 10:37:46 INFO mapred.JobClient: FILE_BYTES_READ=3482158781
09/06/24 10:37:46 INFO mapred.JobClient: FILE_BYTES_WRITTEN=5117707908
09/06/24 10:37:46 INFO mapred.JobClient: Map-Reduce Framework
09/06/24 10:37:46 INFO mapred.JobClient: Reduce input groups=4324900
09/06/24 10:37:46 INFO mapred.JobClient: Combine output records=0
09/06/24 10:37:46 INFO mapred.JobClient: Map input records=58443908
09/06/24 10:37:46 INFO mapred.JobClient: Reduce shuffle bytes=1592197606
09/06/24 10:37:46 INFO mapred.JobClient: Reduce output records=4324900
09/06/24 10:37:46 INFO mapred.JobClient: Spilled Records=183879083
09/06/24 10:37:46 INFO mapred.JobClient: Map output bytes=1521158516
09/06/24 10:37:46 INFO mapred.JobClient: Map input bytes=0
09/06/24 10:37:46 INFO mapred.JobClient: Combine input records=0
09/06/24 10:37:46 INFO mapred.JobClient: Map output records=58443908
09/06/24 10:37:46 INFO mapred.JobClient: Reduce input records=58443908
[had...@server55 ~]$
=======================================================================
The job took a while as you can see. when i run row counter it takes about
the same time.
job output:
Job Setup: Successful
Status: Succeeded
Started at: Wed Jun 24 09:10:44 PDT 2009
Finished at: Wed Jun 24 10:37:46 PDT 2009
Finished in: 1hrs, 27mins, 1sec
Job Cleanup: Successful
--------------------------------------------------------------------------------
Kind % Complete NumTasks Pending Running Complete
Killed
Failed/KilledTask Attempts
map 100.00% 28 0 0
28 0 0 / 7
reduce 100.00% 6 0 0
6 0 0 / 2
Counter Map
Reduce Total
Job Counters
=============================================================================
-Launched reduce tasks 0
0 8
-Rack-local map tasks 0
0 9
-Launched map tasks 0
0 35
-Data-local map tasks 0
0 26
FileSystemCounters
=============================================================================
-FILE_BYTES_READ 1,844,112,413
1,638,046,368 3,482,158,781
-FILE_BYTES_WRITTEN 3,479,661,540
1,638,046,368 5,117,707,908
Map-Reduce Framework
=============================================================================
-Reduce input groups 0
4,324,900 4,324,900
-Combine output records 0
0 0
-Map input records 58,443,908
0 58,443,908
-Reduce shuffle bytes 0
1,592,197,606 1,592,197,606
-Reduce output records 0
4,324,900 4,324,900
-Spilled Records 125,435,175
58,443,908 183,879,083
-Map output bytes 1,521,158,516
0 1,521,158,516
-Map input bytes 0
0 0
-Map output records 58,443,908
0 58,443,908
-Combine input records 0
0 0
-Reduce input records 0
58,443,908 58,443,908
=======================================================================
Also I don't think the output table is working correctly. Some gets work
from shell and some don't. Here is what i get when they don't:
NativeException: org.apache.hadoop.hbase.client.RetriesExhaustedException:
Trying to contact region server null for region , row 'ROW|IM TRYING TO
GET', but failed after 5 attempts.
Exceptions:
java.io.IOException: HRegionInfo was null or empty in .META.
java.io.IOException: HRegionInfo was null or empty in .META.
java.io.IOException: HRegionInfo was null or empty in .META.
java.io.IOException: HRegionInfo was null or empty in .META.
java.io.IOException: HRegionInfo was null or empty in .META.
from org/apache/hadoop/hbase/client/HConnectionManager.java:935:in
`getRegionServerWithRetries'
from org/apache/hadoop/hbase/client/HTable.java:410:in `get'
from org/apache/hadoop/hbase/client/HTable.java:995:in `getRow'
from org/apache/hadoop/hbase/client/HTable.java:953:in `getRow'
from org/apache/hadoop/hbase/client/HTable.java:841:in `getRow'
from org/apache/hadoop/hbase/client/HTable.java:785:in `getRow'
from sun/reflect/NativeMethodAccessorImpl.java:-2:in `invoke0'
from sun/reflect/NativeMethodAccessorImpl.java:39:in `invoke'
from sun/reflect/DelegatingMethodAccessorImpl.java:25:in `invoke'
from java/lang/reflect/Method.java:597:in `invoke'
from org/jruby/javasupport/JavaMethod.java:298:in
`invokeWithExceptionHandling'
from org/jruby/javasupport/JavaMethod.java:259:in `invoke'
from org/jruby/java/invokers/InstanceMethodInvoker.java:44:in `call'
from org/jruby/runtime/callsite/CachingCallSite.java:110:in `call'
from org/jruby/ast/CallOneArgNode.java:57:in `interpret'
from org/jruby/ast/LocalAsgnNode.java:123:in `interpret'
... 114 levels...
from
home/hadoop/hbase_minus_0_dot_20_dot_0_minus_alpha/bin/$_dot_dot_/bin/hirb#start:-1:in
`call'
from org/jruby/internal/runtime/methods/DynamicMethod.java:226:in
`call'
from org/jruby/internal/runtime/methods/CompiledMethod.java:211:in
`call'
from org/jruby/internal/runtime/methods/CompiledMethod.java:71:in
`call'
from org/jruby/runtime/callsite/CachingCallSite.java:253:in
`cacheAndCall'
from org/jruby/runtime/callsite/CachingCallSite.java:72:in `call'
from
home/hadoop/hbase_minus_0_dot_20_dot_0_minus_alpha/bin/$_dot_dot_/bin/hirb.rb:474:in
`__file__'
from
home/hadoop/hbase_minus_0_dot_20_dot_0_minus_alpha/bin/$_dot_dot_/bin/hirb.rb:-1:in
`load'
from org/jruby/Ruby.java:577:in `runScript'
from org/jruby/Ruby.java:480:in `runNormally'
from org/jruby/Ruby.java:354:in `runFromMain'
from org/jruby/Main.java:229:in `run'
from org/jruby/Main.java:110:in `run'
from org/jruby/Main.java:94:in `main'
from /home/hadoop/hbase-0.20.0-alpha/bin/../bin/hirb.rb:371:in `get'
========================================================================
--
View this message in context:
http://www.nabble.com/Running-programs-under-HBase-0.20.0-alpha-tp24152144p24190083.html
Sent from the HBase User mailing list archive at Nabble.com.
