Grokbase Groups HBase user June 2008
FAQ
One of the servers that acts as a hadoop and hbase node in our cluster
went down. After the machine was brought back up I restarted hbase but
could not interact with it. After checking the logs on all 3 of our
machines I found a ton of stack traces like the following:

2008-06-26 23:07:56,683 ERROR org.apache.hadoop.hbase.HRegionServer:
error opening region -ROOT-,,0
java.io.EOFException
at java.io.DataInputStream.readFully(DataInputStream.java:178)
at java.io.DataInputStream.readFully(DataInputStream.java:152)
at org.apache.hadoop.io.SequenceFile
$Reader.init(SequenceFile.java:1434)
at org.apache.hadoop.io.SequenceFile
$Reader.<init>(SequenceFile.java:1411)
at org.apache.hadoop.io.SequenceFile
$Reader.<init>(SequenceFile.java:1400)
at org.apache.hadoop.io.SequenceFile
$Reader.(MapFile.java:254)
at org.apache.hadoop.io.MapFile$Reader.<init>(MapFile.java:242)
at org.apache.hadoop.hbase.HStoreFile$HbaseMapFile
$HbaseReader.<init>(HStoreFile.java:554)
at org.apache.hadoop.hbase.HStoreFile$BloomFilterMapFile
$Reader.(HStoreFile.java:382)
at org.apache.hadoop.hbase.HStore.(HRegion.java:431)
at
org.apache.hadoop.hbase.HRegionServer.openRegion(HRegionServer.java:
1258)
at org.apache.hadoop.hbase.HRegionServer
$Worker.run(HRegionServer.java:1204)
at java.lang.Thread.run(Thread.java:595)

The machine logging all these errors is not the machine that went down
and I'm not sure what the recovery procedure is for this error.

I appreciate any assistance.

Thanks in advance

Preston Price
[email protected]

Search Discussions

  • Stack at Jun 27, 2008 at 12:07 am
    Try with the 0.1.3 release candidate 5:
    http://people.apache.org/~stack/hbase-0.1.3-candidate-5/

    It has fixes to deal with corrupted log files left over after a
    regionserver crash (HBASE-646, 648).

    The 'corruption' was likely because when the regionserver went down, it
    didn't close its open log files in hdfs so a few log files of zero size
    were left over; the edits these Write-Ahead Logs were carrying were
    lost. Previous to the release candidate, we didn't deal well when we
    came across these empty files.

    Until we have appends in hdfs (HADOOP-1700 -- though a subset will be
    available in hadoop-0.18 that may be sufficient to our needs), data loss
    continues to be a fact of hbase life.

    Yours,
    St.Ack


    Preston Price wrote:
    One of the servers that acts as a hadoop and hbase node in our cluster
    went down. After the machine was brought back up I restarted hbase but
    could not interact with it. After checking the logs on all 3 of our
    machines I found a ton of stack traces like the following:

    2008-06-26 23:07:56,683 ERROR org.apache.hadoop.hbase.HRegionServer:
    error opening region -ROOT-,,0
    java.io.EOFException
    at java.io.DataInputStream.readFully(DataInputStream.java:178)
    at java.io.DataInputStream.readFully(DataInputStream.java:152)
    at
    org.apache.hadoop.io.SequenceFile$Reader.init(SequenceFile.java:1434)
    at
    org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1411)
    at
    org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1400)
    at
    org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1395)
    at org.apache.hadoop.io.MapFile$Reader.<init>(MapFile.java:254)
    at org.apache.hadoop.io.MapFile$Reader.<init>(MapFile.java:242)
    at
    org.apache.hadoop.hbase.HStoreFile$HbaseMapFile$HbaseReader.<init>(HStoreFile.java:554)

    at
    org.apache.hadoop.hbase.HStoreFile$BloomFilterMapFile$Reader.<init>(HStoreFile.java:609)

    at
    org.apache.hadoop.hbase.HStoreFile.getReader(HStoreFile.java:382)
    at org.apache.hadoop.hbase.HStore.<init>(HStore.java:849)
    at org.apache.hadoop.hbase.HRegion.<init>(HRegion.java:431)
    at
    org.apache.hadoop.hbase.HRegionServer.openRegion(HRegionServer.java:1258)
    at
    org.apache.hadoop.hbase.HRegionServer$Worker.run(HRegionServer.java:1204)
    at java.lang.Thread.run(Thread.java:595)

    The machine logging all these errors is not the machine that went down
    and I'm not sure what the recovery procedure is for this error.

    I appreciate any assistance.

    Thanks in advance

    Preston Price
    [email protected]

  • Jonathan Gray at Jun 27, 2008 at 2:50 pm
    I was running tests on 0.1.3 RC5 and everything was running fine. I had
    just recently added a bloom filter to a new family to do some testing with
    that (during table creation, this was not added to an already created table
    or family).

    The system appeared to be running fine, but when I took it offline to try
    one of my own patches (related only to the web panel), each regionserver is
    now getting knocked out during startup.

    There are probably on the order of 300,000 columns spread across 1500 rows
    or so within the family in question.

    RegionServer log below (this happens on each regionserver one by one as the
    table gets reassigned around the cluster)


    2008-06-26 17:50:44,669 INFO org.apache.hadoop.ipc.metrics.RpcMetrics:
    Initializing RPC Metrics with hostName=60020, port=60020
    2008-06-26 17:50:44,730 DEBUG org.apache.hadoop.hbase.HRegionServer: Telling
    master at mb0:60000 that we are up
    2008-06-26 17:50:44,789 DEBUG org.apache.hadoop.hbase.HRegionServer: Done
    telling master we are up
    2008-06-26 17:50:44,790 DEBUG org.apache.hadoop.hbase.HRegionServer: Config
    from master: fs.default.name=hdfs://mb0:9000/hbase
    2008-06-26 17:50:44,790 DEBUG org.apache.hadoop.hbase.HRegionServer: Config
    from master: hbase.rootdir=hdfs://mb0:9000/hbase
    2008-06-26 17:50:44,898 DEBUG org.apache.hadoop.hbase.HRegionServer: Log dir
    hdfs://mb0:9000/hbase/log_192.168.249.229_1214527844723_60020
    2008-06-26 17:50:44,952 INFO org.apache.hadoop.hbase.HLog: New log writer
    created at /hbase/log_192.168.249.229_1214527844723_60020/hlog.dat.000
    2008-06-26 17:50:44,998 INFO org.mortbay.util.Credential: Checking Resource
    aliases
    2008-06-26 17:50:45,031 INFO org.mortbay.http.HttpServer: Version
    Jetty/5.1.4
    2008-06-26 17:50:45,032 INFO org.mortbay.util.Container: Started
    HttpContext[/static,/static]
    2008-06-26 17:50:45,032 INFO org.mortbay.util.Container: Started
    HttpContext[/logs,/logs]
    2008-06-26 17:50:45,306 INFO org.mortbay.util.Container: Started
    [email protected]
    2008-06-26 17:50:45,336 INFO org.mortbay.util.Container: Started
    WebApplicationContext[/,/]
    2008-06-26 17:50:45,338 INFO org.mortbay.http.SocketListener: Started
    SocketListener on 0.0.0.0:60030
    2008-06-26 17:50:45,338 INFO org.mortbay.util.Container: Started
    [email protected]
    2008-06-26 17:50:45,338 INFO org.apache.hadoop.ipc.Server: IPC Server
    Responder: starting
    2008-06-26 17:50:45,339 INFO org.apache.hadoop.ipc.Server: IPC Server
    listener on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 0 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 1 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 2 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 3 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 4 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 5 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 6 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 7 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 8 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 9 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.hbase.HRegionServer:
    HRegionServer started at: 192.168.249.229:60020
    2008-06-26 17:50:48,347 INFO org.apache.hadoop.hbase.HRegionServer:
    MSG_REGION_OPEN : .META.,,1
    2008-06-26 17:50:48,360 DEBUG org.apache.hadoop.hbase.HRegion: Opening
    region .META.,,1/1028785192
    2008-06-26 17:50:48,385 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/.META./1028785192/info/info/1015642998673918215, isReference=false
    2008-06-26 17:50:48,408 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1028785192/info, max sequence id 143
    2008-06-26 17:50:48,433 INFO org.apache.hadoop.util.NativeCodeLoader: Loaded
    the native-hadoop library
    2008-06-26 17:50:48,434 INFO org.apache.hadoop.io.compress.zlib.ZlibFactory:
    Successfully loaded & initialized native-zlib library
    2008-06-26 17:50:48,449 DEBUG org.apache.hadoop.hbase.HRegion: Next sequence
    id for region .META.,,1 is 144
    2008-06-26 17:50:48,451 INFO org.apache.hadoop.hbase.HRegion: region
    .META.,,1/1028785192 available
    2008-06-26 17:50:48,451 DEBUG org.apache.hadoop.hbase.HRegionServer:
    Compaction requested for region: .META.,,1
    2008-06-26 17:50:48,451 INFO org.apache.hadoop.hbase.HRegion: checking
    compaction on region .META.,,1
    2008-06-26 17:50:48,451 DEBUG org.apache.hadoop.hbase.HLog: changing
    sequence number from 0 to 144
    2008-06-26 17:50:48,453 INFO org.apache.hadoop.hbase.HRegion: checking
    compaction completed on region .META.,,1; status: false; 0sec
    2008-06-26 17:51:00,359 INFO org.apache.hadoop.hbase.HRegionServer:
    MSG_REGION_OPEN : users,,1214519037805
    2008-06-26 17:51:00,360 DEBUG org.apache.hadoop.hbase.HRegion: Opening
    region users,,1214519037805/1507248414
    2008-06-26 17:51:00,364 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/apps, max sequence id -1
    2008-06-26 17:51:00,370 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/author, max sequence id -1
    2008-06-26 17:51:00,373 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/cfrecs, max sequence id -1
    2008-06-26 17:51:00,377 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/clusters, max sequence id -1
    2008-06-26 17:51:00,392 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/content/info/4407963525386088249, isReference=false
    2008-06-26 17:51:00,399 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/content, max sequence id 82768
    2008-06-26 17:51:00,430 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/events, max sequence id -1
    2008-06-26 17:51:00,437 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/folders/info/7639276499945756112, isReference=false
    2008-06-26 17:51:00,444 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/folders, max sequence id 1947944
    2008-06-26 17:51:00,500 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/friends/info/4259950009198817251, isReference=false
    2008-06-26 17:51:00,510 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/friends, max sequence id 82768
    2008-06-26 17:51:00,536 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/groups/info/8731921527552018851, isReference=false
    2008-06-26 17:51:00,542 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/groups, max sequence id 82768
    2008-06-26 17:51:00,555 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/iclusters, max sequence id -1
    2008-06-26 17:51:00,562 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/read/info/1697858939213451838, isReference=false
    2008-06-26 17:51:00,565 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/read/info/367601598118935005, isReference=false
    2008-06-26 17:51:00,577 DEBUG org.apache.hadoop.hbase.HStore: Loaded 2
    file(s) in hstore 1507248414/read, max sequence id 1947944
    2008-06-26 17:51:01,009 DEBUG org.apache.hadoop.hbase.HStore: loading bloom
    filter for 1507248414/readbloom
    2008-06-26 17:51:01,898 ERROR org.apache.hadoop.hbase.HRegionServer: error
    opening region users,,1214519037805
    java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.listPaths(DFSClient.java:446)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.listStatus(DistributedFileSystem
    .java:170)
    at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:569)
    at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:614)
    at org.apache.hadoop.fs.FileSystem.listPaths(FileSystem.java:645)
    at org.apache.hadoop.fs.FileSystem.listPaths(FileSystem.java:627)
    at org.apache.hadoop.hbase.HStore.loadHStoreFiles(HStore.java:1001)
    at org.apache.hadoop.hbase.HStore.(HRegion.java:431)
    at
    org.apache.hadoop.hbase.HRegionServer.openRegion(HRegionServer.java:1256)
    at
    org.apache.hadoop.hbase.HRegionServer$Worker.run(HRegionServer.java:1202)
    at java.lang.Thread.run(Thread.java:636)
    2008-06-26 17:51:02,444 ERROR org.apache.hadoop.hbase.HRegionServer: Error
    opening scanner (fsOk: true)
    java.io.IOException: HStoreScanner failed construction
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.(HStore.java:2816)
    at org.apache.hadoop.hbase.HStore.getScanner(HStore.java:2431)
    at
    org.apache.hadoop.hbase.HRegion$HScanner.(HRegion.java:1375)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1585)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.getFileInfo(DFSClient.java:451)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSys
    tem.java:343)
    at org.apache.hadoop.fs.FileSystem.getLength(FileSystem.java:512)
    at
    org.apache.hadoop.io.SequenceFile$Reader.(SequenceFile.java:1395)
    at org.apache.hadoop.io.MapFile$Reader.(MapFile.java:242)
    at
    org.apache.hadoop.hbase.HStoreFile$HbaseMapFile$HbaseReader.<init>(HStoreFil
    e.java:555)
    at
    org.apache.hadoop.hbase.HStoreFile$BloomFilterMapFile$Reader.<init>(HStoreFi
    le.java:607)
    at org.apache.hadoop.hbase.HStoreFile.getReader(HStoreFile.java:381)
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.openReaders(HStore.java:2527
    )
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.<init>(HStore.java:2497)
    ... 11 more
    2008-06-26 17:51:02,445 ERROR org.apache.hadoop.hbase.util.FSUtils: file
    system close failed:
    java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.close(DFSClient.java:178)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.close(DistributedFileSystem.java
    :190)
    at
    org.apache.hadoop.hbase.util.FSUtils.checkFileSystemAvailable(FSUtils.java:7
    3)
    at
    org.apache.hadoop.hbase.HRegionServer.checkFileSystem(HRegionServer.java:177
    4)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1598)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,446 FATAL org.apache.hadoop.hbase.HRegionServer:
    Shutting down HRegionServer: file system not available
    java.io.IOException: File system is not available
    at
    org.apache.hadoop.hbase.util.FSUtils.checkFileSystemAvailable(FSUtils.java:7
    7)
    at
    org.apache.hadoop.hbase.HRegionServer.checkFileSystem(HRegionServer.java:177
    4)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1598)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.exists(DFSClient.java:432)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.exists(DistributedFileSystem.jav
    a:153)
    at
    org.apache.hadoop.hbase.util.FSUtils.checkFileSystemAvailable(FSUtils.java:6
    5)
    ... 8 more
    2008-06-26 17:51:02,446 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 8 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@2fe6e305, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: HStoreScanner failed construction
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.(HStore.java:2816)
    at org.apache.hadoop.hbase.HStore.getScanner(HStore.java:2431)
    at
    org.apache.hadoop.hbase.HRegion$HScanner.(HRegion.java:1375)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1585)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.getFileInfo(DFSClient.java:451)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSys
    tem.java:343)
    at org.apache.hadoop.fs.FileSystem.getLength(FileSystem.java:512)
    at
    org.apache.hadoop.io.SequenceFile$Reader.(SequenceFile.java:1395)
    at org.apache.hadoop.io.MapFile$Reader.(MapFile.java:242)
    at
    org.apache.hadoop.hbase.HStoreFile$HbaseMapFile$HbaseReader.<init>(HStoreFil
    e.java:555)
    at
    org.apache.hadoop.hbase.HStoreFile$BloomFilterMapFile$Reader.<init>(HStoreFi
    le.java:607)
    at org.apache.hadoop.hbase.HStoreFile.getReader(HStoreFile.java:381)
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.openReaders(HStore.java:2527
    )
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.<init>(HStore.java:2497)
    ... 11 more
    2008-06-26 17:51:02,457 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 9 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@5f4275d4, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,464 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 0 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@802b249, , 9223372036854775807, null) from
    192.168.249.230:
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,471 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 1 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@6906daba, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,478 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 2 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@41021f34, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:03,359 INFO org.apache.hadoop.hbase.Leases:
    regionserver/0:0:0:0:0:0:0:0:60020 closing leases
    2008-06-26 17:51:03,359 INFO org.apache.hadoop.hbase.Leases$LeaseMonitor:
    regionserver/0:0:0:0:0:0:0:0:60020.leaseChecker exiting
    2008-06-26 17:51:03,359 INFO org.apache.hadoop.hbase.Leases:
    regionserver/0:0:0:0:0:0:0:0:60020 closed leases
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: Stopping server
    on 60020
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 1 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 0 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 2 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 3 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 5 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 6 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 9 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 7 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 8 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 4 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: Stopping IPC
    Server listener on 60020
    2008-06-26 17:51:03,361 INFO org.apache.hadoop.ipc.Server: Stopping IPC
    Server Responder
    2008-06-26 17:51:03,361 INFO org.apache.hadoop.hbase.HRegionServer: Stopping
    infoServer
    2008-06-26 17:51:03,361 INFO org.mortbay.util.ThreadedServer: Stopping
    Acceptor ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=60030]
    2008-06-26 17:51:03,362 INFO org.mortbay.http.SocketListener: Stopped
    SocketListener on 0.0.0.0:60030
    2008-06-26 17:51:03,412 INFO org.mortbay.util.Container: Stopped
    HttpContext[/static,/static]
    2008-06-26 17:51:03,453 INFO org.mortbay.util.Container: Stopped
    HttpContext[/logs,/logs]
    2008-06-26 17:51:03,454 INFO org.mortbay.util.Container: Stopped
    [email protected]
    2008-06-26 17:51:03,507 INFO org.mortbay.util.Container: Stopped
    WebApplicationContext[/,/]
    2008-06-26 17:51:03,507 INFO org.mortbay.util.Container: Stopped
    [email protected]
    2008-06-26 17:51:03,507 INFO org.apache.hadoop.hbase.HRegionServer:
    regionserver/0:0:0:0:0:0:0:0:60020.cacheFlusher exiting
    2008-06-26 17:51:03,507 INFO org.apache.hadoop.hbase.HRegionServer:
    regionserver/0:0:0:0:0:0:0:0:60020.compactor exiting
    2008-06-26 17:51:03,507 INFO org.apache.hadoop.hbase.HRegionServer: aborting
    server at: 192.168.249.229:60020
    2008-06-26 17:51:11,900 INFO org.apache.hadoop.hbase.HRegionServer: worker
    thread exiting
    2008-06-26 17:51:11,900 INFO org.apache.hadoop.hbase.HRegionServer:
    regionserver/0:0:0:0:0:0:0:0:60020 exiting
    2008-06-26 17:51:11,901 INFO org.apache.hadoop.hbase.HRegionServer: Starting
    shutdown thread.
    2008-06-26 17:51:11,901 INFO org.apache.hadoop.hbase.HRegionServer: Shutdown
    thread complete




    Thanks for any help.

    Jonathan Gray, Streamy.com
  • Jonathan Gray at Jun 27, 2008 at 3:22 pm
    Note: There does not appear to be any abnormal behavior according to the
    Hadoop namenode and datanode logs.

    Unfortunately my team needs to get to work so I have to reformat to get the
    system out of this state. I will be applying the same load again so the
    same issue may arise.


    Jonathan Gray
    Streamy

    -----Original Message-----
    From: Jonathan Gray
    Sent: Friday, June 27, 2008 7:48 AM
    To: [email protected]
    Subject: During startup, RegionServer crashes while loading bloom filter on
    single family

    I was running tests on 0.1.3 RC5 and everything was running fine. I had
    just recently added a bloom filter to a new family to do some testing with
    that (during table creation, this was not added to an already created table
    or family).

    The system appeared to be running fine, but when I took it offline to try
    one of my own patches (related only to the web panel), each regionserver is
    now getting knocked out during startup.

    There are probably on the order of 300,000 columns spread across 1500 rows
    or so within the family in question.

    RegionServer log below (this happens on each regionserver one by one as the
    table gets reassigned around the cluster)


    2008-06-26 17:50:44,669 INFO org.apache.hadoop.ipc.metrics.RpcMetrics:
    Initializing RPC Metrics with hostName=60020, port=60020
    2008-06-26 17:50:44,730 DEBUG org.apache.hadoop.hbase.HRegionServer: Telling
    master at mb0:60000 that we are up
    2008-06-26 17:50:44,789 DEBUG org.apache.hadoop.hbase.HRegionServer: Done
    telling master we are up
    2008-06-26 17:50:44,790 DEBUG org.apache.hadoop.hbase.HRegionServer: Config
    from master: fs.default.name=hdfs://mb0:9000/hbase
    2008-06-26 17:50:44,790 DEBUG org.apache.hadoop.hbase.HRegionServer: Config
    from master: hbase.rootdir=hdfs://mb0:9000/hbase
    2008-06-26 17:50:44,898 DEBUG org.apache.hadoop.hbase.HRegionServer: Log dir
    hdfs://mb0:9000/hbase/log_192.168.249.229_1214527844723_60020
    2008-06-26 17:50:44,952 INFO org.apache.hadoop.hbase.HLog: New log writer
    created at /hbase/log_192.168.249.229_1214527844723_60020/hlog.dat.000
    2008-06-26 17:50:44,998 INFO org.mortbay.util.Credential: Checking Resource
    aliases
    2008-06-26 17:50:45,031 INFO org.mortbay.http.HttpServer: Version
    Jetty/5.1.4
    2008-06-26 17:50:45,032 INFO org.mortbay.util.Container: Started
    HttpContext[/static,/static]
    2008-06-26 17:50:45,032 INFO org.mortbay.util.Container: Started
    HttpContext[/logs,/logs]
    2008-06-26 17:50:45,306 INFO org.mortbay.util.Container: Started
    [email protected]
    2008-06-26 17:50:45,336 INFO org.mortbay.util.Container: Started
    WebApplicationContext[/,/]
    2008-06-26 17:50:45,338 INFO org.mortbay.http.SocketListener: Started
    SocketListener on 0.0.0.0:60030
    2008-06-26 17:50:45,338 INFO org.mortbay.util.Container: Started
    [email protected]
    2008-06-26 17:50:45,338 INFO org.apache.hadoop.ipc.Server: IPC Server
    Responder: starting
    2008-06-26 17:50:45,339 INFO org.apache.hadoop.ipc.Server: IPC Server
    listener on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 0 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 1 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 2 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 3 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 4 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 5 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 6 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 7 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 8 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 9 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.hbase.HRegionServer:
    HRegionServer started at: 192.168.249.229:60020
    2008-06-26 17:50:48,347 INFO org.apache.hadoop.hbase.HRegionServer:
    MSG_REGION_OPEN : .META.,,1
    2008-06-26 17:50:48,360 DEBUG org.apache.hadoop.hbase.HRegion: Opening
    region .META.,,1/1028785192
    2008-06-26 17:50:48,385 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/.META./1028785192/info/info/1015642998673918215, isReference=false
    2008-06-26 17:50:48,408 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1028785192/info, max sequence id 143
    2008-06-26 17:50:48,433 INFO org.apache.hadoop.util.NativeCodeLoader: Loaded
    the native-hadoop library
    2008-06-26 17:50:48,434 INFO org.apache.hadoop.io.compress.zlib.ZlibFactory:
    Successfully loaded & initialized native-zlib library
    2008-06-26 17:50:48,449 DEBUG org.apache.hadoop.hbase.HRegion: Next sequence
    id for region .META.,,1 is 144
    2008-06-26 17:50:48,451 INFO org.apache.hadoop.hbase.HRegion: region
    .META.,,1/1028785192 available
    2008-06-26 17:50:48,451 DEBUG org.apache.hadoop.hbase.HRegionServer:
    Compaction requested for region: .META.,,1
    2008-06-26 17:50:48,451 INFO org.apache.hadoop.hbase.HRegion: checking
    compaction on region .META.,,1
    2008-06-26 17:50:48,451 DEBUG org.apache.hadoop.hbase.HLog: changing
    sequence number from 0 to 144
    2008-06-26 17:50:48,453 INFO org.apache.hadoop.hbase.HRegion: checking
    compaction completed on region .META.,,1; status: false; 0sec
    2008-06-26 17:51:00,359 INFO org.apache.hadoop.hbase.HRegionServer:
    MSG_REGION_OPEN : users,,1214519037805
    2008-06-26 17:51:00,360 DEBUG org.apache.hadoop.hbase.HRegion: Opening
    region users,,1214519037805/1507248414
    2008-06-26 17:51:00,364 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/apps, max sequence id -1
    2008-06-26 17:51:00,370 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/author, max sequence id -1
    2008-06-26 17:51:00,373 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/cfrecs, max sequence id -1
    2008-06-26 17:51:00,377 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/clusters, max sequence id -1
    2008-06-26 17:51:00,392 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/content/info/4407963525386088249, isReference=false
    2008-06-26 17:51:00,399 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/content, max sequence id 82768
    2008-06-26 17:51:00,430 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/events, max sequence id -1
    2008-06-26 17:51:00,437 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/folders/info/7639276499945756112, isReference=false
    2008-06-26 17:51:00,444 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/folders, max sequence id 1947944
    2008-06-26 17:51:00,500 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/friends/info/4259950009198817251, isReference=false
    2008-06-26 17:51:00,510 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/friends, max sequence id 82768
    2008-06-26 17:51:00,536 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/groups/info/8731921527552018851, isReference=false
    2008-06-26 17:51:00,542 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/groups, max sequence id 82768
    2008-06-26 17:51:00,555 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/iclusters, max sequence id -1
    2008-06-26 17:51:00,562 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/read/info/1697858939213451838, isReference=false
    2008-06-26 17:51:00,565 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/read/info/367601598118935005, isReference=false
    2008-06-26 17:51:00,577 DEBUG org.apache.hadoop.hbase.HStore: Loaded 2
    file(s) in hstore 1507248414/read, max sequence id 1947944
    2008-06-26 17:51:01,009 DEBUG org.apache.hadoop.hbase.HStore: loading bloom
    filter for 1507248414/readbloom
    2008-06-26 17:51:01,898 ERROR org.apache.hadoop.hbase.HRegionServer: error
    opening region users,,1214519037805
    java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.listPaths(DFSClient.java:446)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.listStatus(DistributedFileSystem
    .java:170)
    at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:569)
    at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:614)
    at org.apache.hadoop.fs.FileSystem.listPaths(FileSystem.java:645)
    at org.apache.hadoop.fs.FileSystem.listPaths(FileSystem.java:627)
    at org.apache.hadoop.hbase.HStore.loadHStoreFiles(HStore.java:1001)
    at org.apache.hadoop.hbase.HStore.(HRegion.java:431)
    at
    org.apache.hadoop.hbase.HRegionServer.openRegion(HRegionServer.java:1256)
    at
    org.apache.hadoop.hbase.HRegionServer$Worker.run(HRegionServer.java:1202)
    at java.lang.Thread.run(Thread.java:636)
    2008-06-26 17:51:02,444 ERROR org.apache.hadoop.hbase.HRegionServer: Error
    opening scanner (fsOk: true)
    java.io.IOException: HStoreScanner failed construction
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.(HStore.java:2816)
    at org.apache.hadoop.hbase.HStore.getScanner(HStore.java:2431)
    at
    org.apache.hadoop.hbase.HRegion$HScanner.(HRegion.java:1375)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1585)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.getFileInfo(DFSClient.java:451)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSys
    tem.java:343)
    at org.apache.hadoop.fs.FileSystem.getLength(FileSystem.java:512)
    at
    org.apache.hadoop.io.SequenceFile$Reader.(SequenceFile.java:1395)
    at org.apache.hadoop.io.MapFile$Reader.(MapFile.java:242)
    at
    org.apache.hadoop.hbase.HStoreFile$HbaseMapFile$HbaseReader.<init>(HStoreFil
    e.java:555)
    at
    org.apache.hadoop.hbase.HStoreFile$BloomFilterMapFile$Reader.<init>(HStoreFi
    le.java:607)
    at org.apache.hadoop.hbase.HStoreFile.getReader(HStoreFile.java:381)
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.openReaders(HStore.java:2527
    )
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.<init>(HStore.java:2497)
    ... 11 more
    2008-06-26 17:51:02,445 ERROR org.apache.hadoop.hbase.util.FSUtils: file
    system close failed:
    java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.close(DFSClient.java:178)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.close(DistributedFileSystem.java
    :190)
    at
    org.apache.hadoop.hbase.util.FSUtils.checkFileSystemAvailable(FSUtils.java:7
    3)
    at
    org.apache.hadoop.hbase.HRegionServer.checkFileSystem(HRegionServer.java:177
    4)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1598)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,446 FATAL org.apache.hadoop.hbase.HRegionServer:
    Shutting down HRegionServer: file system not available
    java.io.IOException: File system is not available
    at
    org.apache.hadoop.hbase.util.FSUtils.checkFileSystemAvailable(FSUtils.java:7
    7)
    at
    org.apache.hadoop.hbase.HRegionServer.checkFileSystem(HRegionServer.java:177
    4)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1598)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.exists(DFSClient.java:432)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.exists(DistributedFileSystem.jav
    a:153)
    at
    org.apache.hadoop.hbase.util.FSUtils.checkFileSystemAvailable(FSUtils.java:6
    5)
    ... 8 more
    2008-06-26 17:51:02,446 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 8 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@2fe6e305, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: HStoreScanner failed construction
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.(HStore.java:2816)
    at org.apache.hadoop.hbase.HStore.getScanner(HStore.java:2431)
    at
    org.apache.hadoop.hbase.HRegion$HScanner.(HRegion.java:1375)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1585)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.getFileInfo(DFSClient.java:451)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSys
    tem.java:343)
    at org.apache.hadoop.fs.FileSystem.getLength(FileSystem.java:512)
    at
    org.apache.hadoop.io.SequenceFile$Reader.(SequenceFile.java:1395)
    at org.apache.hadoop.io.MapFile$Reader.(MapFile.java:242)
    at
    org.apache.hadoop.hbase.HStoreFile$HbaseMapFile$HbaseReader.<init>(HStoreFil
    e.java:555)
    at
    org.apache.hadoop.hbase.HStoreFile$BloomFilterMapFile$Reader.<init>(HStoreFi
    le.java:607)
    at org.apache.hadoop.hbase.HStoreFile.getReader(HStoreFile.java:381)
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.openReaders(HStore.java:2527
    )
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.<init>(HStore.java:2497)
    ... 11 more
    2008-06-26 17:51:02,457 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 9 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@5f4275d4, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,464 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 0 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@802b249, , 9223372036854775807, null) from
    192.168.249.230:
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,471 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 1 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@6906daba, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,478 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 2 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@41021f34, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:03,359 INFO org.apache.hadoop.hbase.Leases:
    regionserver/0:0:0:0:0:0:0:0:60020 closing leases
    2008-06-26 17:51:03,359 INFO org.apache.hadoop.hbase.Leases$LeaseMonitor:
    regionserver/0:0:0:0:0:0:0:0:60020.leaseChecker exiting
    2008-06-26 17:51:03,359 INFO org.apache.hadoop.hbase.Leases:
    regionserver/0:0:0:0:0:0:0:0:60020 closed leases
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: Stopping server
    on 60020
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 1 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 0 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 2 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 3 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 5 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 6 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 9 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 7 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 8 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 4 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: Stopping IPC
    Server listener on 60020
    2008-06-26 17:51:03,361 INFO org.apache.hadoop.ipc.Server: Stopping IPC
    Server Responder
    2008-06-26 17:51:03,361 INFO org.apache.hadoop.hbase.HRegionServer: Stopping
    infoServer
    2008-06-26 17:51:03,361 INFO org.mortbay.util.ThreadedServer: Stopping
    Acceptor ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=60030]
    2008-06-26 17:51:03,362 INFO org.mortbay.http.SocketListener: Stopped
    SocketListener on 0.0.0.0:60030
    2008-06-26 17:51:03,412 INFO org.mortbay.util.Container: Stopped
    HttpContext[/static,/static]
    2008-06-26 17:51:03,453 INFO org.mortbay.util.Container: Stopped
    HttpContext[/logs,/logs]
    2008-06-26 17:51:03,454 INFO org.mortbay.util.Container: Stopped
    [email protected]
    2008-06-26 17:51:03,507 INFO org.mortbay.util.Container: Stopped
    WebApplicationContext[/,/]
    2008-06-26 17:51:03,507 INFO org.mortbay.util.Container: Stopped
    [email protected]
    2008-06-26 17:51:03,507 INFO org.apache.hadoop.hbase.HRegionServer:
    regionserver/0:0:0:0:0:0:0:0:60020.cacheFlusher exiting
    2008-06-26 17:51:03,507 INFO org.apache.hadoop.hbase.HRegionServer:
    regionserver/0:0:0:0:0:0:0:0:60020.compactor exiting
    2008-06-26 17:51:03,507 INFO org.apache.hadoop.hbase.HRegionServer: aborting
    server at: 192.168.249.229:60020
    2008-06-26 17:51:11,900 INFO org.apache.hadoop.hbase.HRegionServer: worker
    thread exiting
    2008-06-26 17:51:11,900 INFO org.apache.hadoop.hbase.HRegionServer:
    regionserver/0:0:0:0:0:0:0:0:60020 exiting
    2008-06-26 17:51:11,901 INFO org.apache.hadoop.hbase.HRegionServer: Starting
    shutdown thread.
    2008-06-26 17:51:11,901 INFO org.apache.hadoop.hbase.HRegionServer: Shutdown
    thread complete




    Thanks for any help.

    Jonathan Gray, Streamy.com
  • Stack at Jul 1, 2008 at 5:08 pm
    Looking at the log below, its reporting that the filesystem is closed:

    java.io.IOException: Filesystem closed

    and


    java.io.IOException: File system is not available


    Is it possible Jon, that HDFS was not running at the time?

    St.Ack





    Jonathan Gray wrote:
    Note: There does not appear to be any abnormal behavior according to the
    Hadoop namenode and datanode logs.

    Unfortunately my team needs to get to work so I have to reformat to get the
    system out of this state. I will be applying the same load again so the
    same issue may arise.


    Jonathan Gray
    Streamy

    -----Original Message-----
    From: Jonathan Gray
    Sent: Friday, June 27, 2008 7:48 AM
    To: [email protected]
    Subject: During startup, RegionServer crashes while loading bloom filter on
    single family

    I was running tests on 0.1.3 RC5 and everything was running fine. I had
    just recently added a bloom filter to a new family to do some testing with
    that (during table creation, this was not added to an already created table
    or family).

    The system appeared to be running fine, but when I took it offline to try
    one of my own patches (related only to the web panel), each regionserver is
    now getting knocked out during startup.

    There are probably on the order of 300,000 columns spread across 1500 rows
    or so within the family in question.

    RegionServer log below (this happens on each regionserver one by one as the
    table gets reassigned around the cluster)


    2008-06-26 17:50:44,669 INFO org.apache.hadoop.ipc.metrics.RpcMetrics:
    Initializing RPC Metrics with hostName=60020, port=60020
    2008-06-26 17:50:44,730 DEBUG org.apache.hadoop.hbase.HRegionServer: Telling
    master at mb0:60000 that we are up
    2008-06-26 17:50:44,789 DEBUG org.apache.hadoop.hbase.HRegionServer: Done
    telling master we are up
    2008-06-26 17:50:44,790 DEBUG org.apache.hadoop.hbase.HRegionServer: Config
    from master: fs.default.name=hdfs://mb0:9000/hbase
    2008-06-26 17:50:44,790 DEBUG org.apache.hadoop.hbase.HRegionServer: Config
    from master: hbase.rootdir=hdfs://mb0:9000/hbase
    2008-06-26 17:50:44,898 DEBUG org.apache.hadoop.hbase.HRegionServer: Log dir
    hdfs://mb0:9000/hbase/log_192.168.249.229_1214527844723_60020
    2008-06-26 17:50:44,952 INFO org.apache.hadoop.hbase.HLog: New log writer
    created at /hbase/log_192.168.249.229_1214527844723_60020/hlog.dat.000
    2008-06-26 17:50:44,998 INFO org.mortbay.util.Credential: Checking Resource
    aliases
    2008-06-26 17:50:45,031 INFO org.mortbay.http.HttpServer: Version
    Jetty/5.1.4
    2008-06-26 17:50:45,032 INFO org.mortbay.util.Container: Started
    HttpContext[/static,/static]
    2008-06-26 17:50:45,032 INFO org.mortbay.util.Container: Started
    HttpContext[/logs,/logs]
    2008-06-26 17:50:45,306 INFO org.mortbay.util.Container: Started
    [email protected]
    2008-06-26 17:50:45,336 INFO org.mortbay.util.Container: Started
    WebApplicationContext[/,/]
    2008-06-26 17:50:45,338 INFO org.mortbay.http.SocketListener: Started
    SocketListener on 0.0.0.0:60030
    2008-06-26 17:50:45,338 INFO org.mortbay.util.Container: Started
    [email protected]
    2008-06-26 17:50:45,338 INFO org.apache.hadoop.ipc.Server: IPC Server
    Responder: starting
    2008-06-26 17:50:45,339 INFO org.apache.hadoop.ipc.Server: IPC Server
    listener on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 0 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 1 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 2 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 3 on 60020: starting
    2008-06-26 17:50:45,340 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 4 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 5 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 6 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 7 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 8 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 9 on 60020: starting
    2008-06-26 17:50:45,341 INFO org.apache.hadoop.hbase.HRegionServer:
    HRegionServer started at: 192.168.249.229:60020
    2008-06-26 17:50:48,347 INFO org.apache.hadoop.hbase.HRegionServer:
    MSG_REGION_OPEN : .META.,,1
    2008-06-26 17:50:48,360 DEBUG org.apache.hadoop.hbase.HRegion: Opening
    region .META.,,1/1028785192
    2008-06-26 17:50:48,385 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/.META./1028785192/info/info/1015642998673918215, isReference=false
    2008-06-26 17:50:48,408 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1028785192/info, max sequence id 143
    2008-06-26 17:50:48,433 INFO org.apache.hadoop.util.NativeCodeLoader: Loaded
    the native-hadoop library
    2008-06-26 17:50:48,434 INFO org.apache.hadoop.io.compress.zlib.ZlibFactory:
    Successfully loaded & initialized native-zlib library
    2008-06-26 17:50:48,449 DEBUG org.apache.hadoop.hbase.HRegion: Next sequence
    id for region .META.,,1 is 144
    2008-06-26 17:50:48,451 INFO org.apache.hadoop.hbase.HRegion: region
    .META.,,1/1028785192 available
    2008-06-26 17:50:48,451 DEBUG org.apache.hadoop.hbase.HRegionServer:
    Compaction requested for region: .META.,,1
    2008-06-26 17:50:48,451 INFO org.apache.hadoop.hbase.HRegion: checking
    compaction on region .META.,,1
    2008-06-26 17:50:48,451 DEBUG org.apache.hadoop.hbase.HLog: changing
    sequence number from 0 to 144
    2008-06-26 17:50:48,453 INFO org.apache.hadoop.hbase.HRegion: checking
    compaction completed on region .META.,,1; status: false; 0sec
    2008-06-26 17:51:00,359 INFO org.apache.hadoop.hbase.HRegionServer:
    MSG_REGION_OPEN : users,,1214519037805
    2008-06-26 17:51:00,360 DEBUG org.apache.hadoop.hbase.HRegion: Opening
    region users,,1214519037805/1507248414
    2008-06-26 17:51:00,364 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/apps, max sequence id -1
    2008-06-26 17:51:00,370 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/author, max sequence id -1
    2008-06-26 17:51:00,373 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/cfrecs, max sequence id -1
    2008-06-26 17:51:00,377 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/clusters, max sequence id -1
    2008-06-26 17:51:00,392 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/content/info/4407963525386088249, isReference=false
    2008-06-26 17:51:00,399 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/content, max sequence id 82768
    2008-06-26 17:51:00,430 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/events, max sequence id -1
    2008-06-26 17:51:00,437 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/folders/info/7639276499945756112, isReference=false
    2008-06-26 17:51:00,444 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/folders, max sequence id 1947944
    2008-06-26 17:51:00,500 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/friends/info/4259950009198817251, isReference=false
    2008-06-26 17:51:00,510 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/friends, max sequence id 82768
    2008-06-26 17:51:00,536 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/groups/info/8731921527552018851, isReference=false
    2008-06-26 17:51:00,542 DEBUG org.apache.hadoop.hbase.HStore: Loaded 1
    file(s) in hstore 1507248414/groups, max sequence id 82768
    2008-06-26 17:51:00,555 DEBUG org.apache.hadoop.hbase.HStore: Loaded 0
    file(s) in hstore 1507248414/iclusters, max sequence id -1
    2008-06-26 17:51:00,562 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/read/info/1697858939213451838, isReference=false
    2008-06-26 17:51:00,565 DEBUG org.apache.hadoop.hbase.HStore: loaded
    /hbase/users/1507248414/read/info/367601598118935005, isReference=false
    2008-06-26 17:51:00,577 DEBUG org.apache.hadoop.hbase.HStore: Loaded 2
    file(s) in hstore 1507248414/read, max sequence id 1947944
    2008-06-26 17:51:01,009 DEBUG org.apache.hadoop.hbase.HStore: loading bloom
    filter for 1507248414/readbloom
    2008-06-26 17:51:01,898 ERROR org.apache.hadoop.hbase.HRegionServer: error
    opening region users,,1214519037805
    java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.listPaths(DFSClient.java:446)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.listStatus(DistributedFileSystem
    .java:170)
    at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:569)
    at org.apache.hadoop.fs.FileSystem.listStatus(FileSystem.java:614)
    at org.apache.hadoop.fs.FileSystem.listPaths(FileSystem.java:645)
    at org.apache.hadoop.fs.FileSystem.listPaths(FileSystem.java:627)
    at org.apache.hadoop.hbase.HStore.loadHStoreFiles(HStore.java:1001)
    at org.apache.hadoop.hbase.HStore.<init>(HStore.java:831)
    at org.apache.hadoop.hbase.HRegion.<init>(HRegion.java:431)
    at
    org.apache.hadoop.hbase.HRegionServer.openRegion(HRegionServer.java:1256)
    at
    org.apache.hadoop.hbase.HRegionServer$Worker.run(HRegionServer.java:1202)
    at java.lang.Thread.run(Thread.java:636)
    2008-06-26 17:51:02,444 ERROR org.apache.hadoop.hbase.HRegionServer: Error
    opening scanner (fsOk: true)
    java.io.IOException: HStoreScanner failed construction
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.<init>(HStore.java:2500)
    at
    org.apache.hadoop.hbase.HStore$HStoreScanner.<init>(HStore.java:2816)
    at org.apache.hadoop.hbase.HStore.getScanner(HStore.java:2431)
    at
    org.apache.hadoop.hbase.HRegion$HScanner.<init>(HRegion.java:1827)
    at org.apache.hadoop.hbase.HRegion.getScanner(HRegion.java:1375)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1585)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.getFileInfo(DFSClient.java:451)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSys
    tem.java:343)
    at org.apache.hadoop.fs.FileSystem.getLength(FileSystem.java:512)
    at
    org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1400)
    at
    org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1395)
    at org.apache.hadoop.io.MapFile$Reader.<init>(MapFile.java:254)
    at org.apache.hadoop.io.MapFile$Reader.<init>(MapFile.java:242)
    at
    org.apache.hadoop.hbase.HStoreFile$HbaseMapFile$HbaseReader.<init>(HStoreFil
    e.java:555)
    at
    org.apache.hadoop.hbase.HStoreFile$BloomFilterMapFile$Reader.<init>(HStoreFi
    le.java:607)
    at org.apache.hadoop.hbase.HStoreFile.getReader(HStoreFile.java:381)
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.openReaders(HStore.java:2527
    )
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.<init>(HStore.java:2497)
    ... 11 more
    2008-06-26 17:51:02,445 ERROR org.apache.hadoop.hbase.util.FSUtils: file
    system close failed:
    java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.close(DFSClient.java:178)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.close(DistributedFileSystem.java
    :190)
    at
    org.apache.hadoop.hbase.util.FSUtils.checkFileSystemAvailable(FSUtils.java:7
    3)
    at
    org.apache.hadoop.hbase.HRegionServer.checkFileSystem(HRegionServer.java:177
    4)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1598)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,446 FATAL org.apache.hadoop.hbase.HRegionServer:
    Shutting down HRegionServer: file system not available
    java.io.IOException: File system is not available
    at
    org.apache.hadoop.hbase.util.FSUtils.checkFileSystemAvailable(FSUtils.java:7
    7)
    at
    org.apache.hadoop.hbase.HRegionServer.checkFileSystem(HRegionServer.java:177
    4)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1598)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.exists(DFSClient.java:432)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.exists(DistributedFileSystem.jav
    a:153)
    at
    org.apache.hadoop.hbase.util.FSUtils.checkFileSystemAvailable(FSUtils.java:6
    5)
    ... 8 more
    2008-06-26 17:51:02,446 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 8 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@2fe6e305, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: HStoreScanner failed construction
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.<init>(HStore.java:2500)
    at
    org.apache.hadoop.hbase.HStore$HStoreScanner.<init>(HStore.java:2816)
    at org.apache.hadoop.hbase.HStore.getScanner(HStore.java:2431)
    at
    org.apache.hadoop.hbase.HRegion$HScanner.<init>(HRegion.java:1827)
    at org.apache.hadoop.hbase.HRegion.getScanner(HRegion.java:1375)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1585)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    Caused by: java.io.IOException: Filesystem closed
    at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:166)
    at org.apache.hadoop.dfs.DFSClient.getFileInfo(DFSClient.java:451)
    at
    org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(DistributedFileSys
    tem.java:343)
    at org.apache.hadoop.fs.FileSystem.getLength(FileSystem.java:512)
    at
    org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1400)
    at
    org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1395)
    at org.apache.hadoop.io.MapFile$Reader.<init>(MapFile.java:254)
    at org.apache.hadoop.io.MapFile$Reader.<init>(MapFile.java:242)
    at
    org.apache.hadoop.hbase.HStoreFile$HbaseMapFile$HbaseReader.<init>(HStoreFil
    e.java:555)
    at
    org.apache.hadoop.hbase.HStoreFile$BloomFilterMapFile$Reader.<init>(HStoreFi
    le.java:607)
    at org.apache.hadoop.hbase.HStoreFile.getReader(HStoreFile.java:381)
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.openReaders(HStore.java:2527
    )
    at
    org.apache.hadoop.hbase.HStore$StoreFileScanner.<init>(HStore.java:2497)
    ... 11 more
    2008-06-26 17:51:02,457 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 9 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@5f4275d4, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,464 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 0 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@802b249, , 9223372036854775807, null) from
    192.168.249.230:
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,471 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 1 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@6906daba, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:02,478 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 2 on 60020, call openScanner(.META.,,1,
    [Lorg.apache.hadoop.io.Text;@41021f34, , 9223372036854775807, null) from
    192.168.249.230
    java.io.IOException: Server not running
    at
    org.apache.hadoop.hbase.HRegionServer.checkOpen(HRegionServer.java:1758)
    at
    org.apache.hadoop.hbase.HRegionServer.openScanner(HRegionServer.java:1567)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
    sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
    )
    at
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
    .java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at
    org.apache.hadoop.hbase.ipc.HbaseRPC$Server.call(HbaseRPC.java:413)
    at org.apache.hadoop.ipc.Server$Handler.run(Server.java:901)
    2008-06-26 17:51:03,359 INFO org.apache.hadoop.hbase.Leases:
    regionserver/0:0:0:0:0:0:0:0:60020 closing leases
    2008-06-26 17:51:03,359 INFO org.apache.hadoop.hbase.Leases$LeaseMonitor:
    regionserver/0:0:0:0:0:0:0:0:60020.leaseChecker exiting
    2008-06-26 17:51:03,359 INFO org.apache.hadoop.hbase.Leases:
    regionserver/0:0:0:0:0:0:0:0:60020 closed leases
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: Stopping server
    on 60020
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 1 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 0 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 2 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 3 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 5 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 6 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 9 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 7 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 8 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: IPC Server
    handler 4 on 60020: exiting
    2008-06-26 17:51:03,360 INFO org.apache.hadoop.ipc.Server: Stopping IPC
    Server listener on 60020
    2008-06-26 17:51:03,361 INFO org.apache.hadoop.ipc.Server: Stopping IPC
    Server Responder
    2008-06-26 17:51:03,361 INFO org.apache.hadoop.hbase.HRegionServer: Stopping
    infoServer
    2008-06-26 17:51:03,361 INFO org.mortbay.util.ThreadedServer: Stopping
    Acceptor ServerSocket[addr=0.0.0.0/0.0.0.0,port=0,localport=60030]
    2008-06-26 17:51:03,362 INFO org.mortbay.http.SocketListener: Stopped
    SocketListener on 0.0.0.0:60030
    2008-06-26 17:51:03,412 INFO org.mortbay.util.Container: Stopped
    HttpContext[/static,/static]
    2008-06-26 17:51:03,453 INFO org.mortbay.util.Container: Stopped
    HttpContext[/logs,/logs]
    2008-06-26 17:51:03,454 INFO org.mortbay.util.Container: Stopped
    [email protected]
    2008-06-26 17:51:03,507 INFO org.mortbay.util.Container: Stopped
    WebApplicationContext[/,/]
    2008-06-26 17:51:03,507 INFO org.mortbay.util.Container: Stopped
    [email protected]
    2008-06-26 17:51:03,507 INFO org.apache.hadoop.hbase.HRegionServer:
    regionserver/0:0:0:0:0:0:0:0:60020.cacheFlusher exiting
    2008-06-26 17:51:03,507 INFO org.apache.hadoop.hbase.HRegionServer:
    regionserver/0:0:0:0:0:0:0:0:60020.compactor exiting
    2008-06-26 17:51:03,507 INFO org.apache.hadoop.hbase.HRegionServer: aborting
    server at: 192.168.249.229:60020
    2008-06-26 17:51:11,900 INFO org.apache.hadoop.hbase.HRegionServer: worker
    thread exiting
    2008-06-26 17:51:11,900 INFO org.apache.hadoop.hbase.HRegionServer:
    regionserver/0:0:0:0:0:0:0:0:60020 exiting
    2008-06-26 17:51:11,901 INFO org.apache.hadoop.hbase.HRegionServer: Starting
    shutdown thread.
    2008-06-26 17:51:11,901 INFO org.apache.hadoop.hbase.HRegionServer: Shutdown
    thread complete




    Thanks for any help.

    Jonathan Gray, Streamy.com

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
groupuser @
categorieshbase, hadoop
postedJun 26, '08 at 11:19p
activeJul 1, '08 at 5:08p
posts5
users3
websitehbase.apache.org

People

Translate

site design / logo © 2023 Grokbase