Hadoop HDFS
  1. Hadoop HDFS
  2. HDFS-8

Interrupting the namenode thread triggers System.exit()

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Minor Minor
    • Resolution: Cannot Reproduce
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: None
    • Labels:
      None

      Description

      My service setup/teardown tests are managing to trigger system exits in the namenode, which seems overkill.

      1. Interrupting the thread that is starting the namesystem up raises a java.nio.channels.ClosedByInterruptException.
      2. This is caught in FSImage.rollFSImage, and handed off to processIOError
      3. This triggers a call to Runtime.getRuntime().exit(-1); "All storage directories are inaccessible.".

      Stack trace to follow. Exiting the JVM is somewhat overkill; if someone has interrupted the thread is is (presumably) because they want to stop the namenode, which may not imply they want to kill the JVM at the same time. Certainly JUnit does not expect it.

      Some possibilities
      -ClosedByInterruptException get handled differently as some form of shutdown request
      -Calls to system exit are factored out into something that can have its behaviour changed by policy options to throw a RuntimeException instead.
      Hosting a Namenode in a security manager that blocks off System.exit() is the simplest workaround; this is fairly simple, but it means that what would be a straight exit does now get turned into an exception, so callers may be surprised by what happens.

        Activity

        Hide
        Steve Loughran added a comment -

        stack trace. FSImage does not like to be interrupted.

        [sf-startdaemon-debug] 08/10/28 12:50:22 [Thread-305] ERROR common.Storage : Cannot write file /tmp/hadoop/dfs/name
        [sf-startdaemon-debug] java.nio.channels.ClosedByInterruptException
        [sf-startdaemon-debug] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184)
        [sf-startdaemon-debug] at sun.nio.ch.FileChannelImpl.position(FileChannelImpl.java:271)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.common.Storage$StorageDirectory.write(Storage.java:268)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.common.Storage$StorageDirectory.write(Storage.java:244)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSImage.rollFSImage(FSImage.java:1316)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSImage.saveFSImage(FSImage.java:1034)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSDirectory.loadFSImage(FSDirectory.java:88)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.initialize(FSNamesystem.java:311)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.<init>(FSNamesystem.java:290)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:165)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.innerStart(NameNode.java:226)
        [sf-startdaemon-debug] at org.apache.hadoop.util.Service.start(Service.java:188)
        [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl.innerDeploy(HadoopServiceImpl.java:479)
        [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl.access$000(HadoopServiceImpl.java:46)
        [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl$ServiceDeployerThread.execute(HadoopServiceImpl.java:628)

        Show
        Steve Loughran added a comment - stack trace. FSImage does not like to be interrupted. [sf-startdaemon-debug] 08/10/28 12:50:22 [Thread-305] ERROR common.Storage : Cannot write file /tmp/hadoop/dfs/name [sf-startdaemon-debug] java.nio.channels.ClosedByInterruptException [sf-startdaemon-debug] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184) [sf-startdaemon-debug] at sun.nio.ch.FileChannelImpl.position(FileChannelImpl.java:271) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.common.Storage$StorageDirectory.write(Storage.java:268) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.common.Storage$StorageDirectory.write(Storage.java:244) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSImage.rollFSImage(FSImage.java:1316) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSImage.saveFSImage(FSImage.java:1034) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSDirectory.loadFSImage(FSDirectory.java:88) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.initialize(FSNamesystem.java:311) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.<init>(FSNamesystem.java:290) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:165) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.innerStart(NameNode.java:226) [sf-startdaemon-debug] at org.apache.hadoop.util.Service.start(Service.java:188) [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl.innerDeploy(HadoopServiceImpl.java:479) [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl.access$000(HadoopServiceImpl.java:46) [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl$ServiceDeployerThread.execute(HadoopServiceImpl.java:628)
        Hide
        Steve Loughran added a comment -

        This is very race condition dependent; a small change in machine timing and the interrupt is handled gracefully by reporting failure to the caller.

        [sf-startdaemon-debug] 08/10/28 13:15:07 [Thread-6] WARN util.Shell : Interrupted while reading the error stream
        [sf-startdaemon-debug] java.lang.InterruptedException
        [sf-startdaemon-debug] at java.lang.Object.wait(Native Method)
        [sf-startdaemon-debug] at java.lang.Thread.join(Thread.java:1143)
        [sf-startdaemon-debug] at java.lang.Thread.join(Thread.java:1196)
        [sf-startdaemon-debug] at org.apache.hadoop.util.Shell.runCommand(Shell.java:189)
        [sf-startdaemon-debug] at org.apache.hadoop.util.Shell.run(Shell.java:134)
        [sf-startdaemon-debug] at org.apache.hadoop.util.Shell$ShellCommandExecutor.execute(Shell.java:286)
        [sf-startdaemon-debug] at org.apache.hadoop.util.Shell.execCommand(Shell.java:338)
        [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.executeShellCommand(UnixUserGroupInformation.java:326)
        [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.getUnixUserName(UnixUserGroupInformation.java:305)
        [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.login(UnixUserGroupInformation.java:232)
        [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.login(UnixUserGroupInformation.java:275)
        [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.login(UnixUserGroupInformation.java:257)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.setConfigurationParameters(FSNamesystem.java:426)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.initialize(FSNamesystem.java:304)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.<init>(FSNamesystem.java:290)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:165)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.innerStart(NameNode.java:226)

        given I am interrupting threads during their initialization, I shouldn't expect things to work. But stopping the JVM is probably inappropriate.

        Show
        Steve Loughran added a comment - This is very race condition dependent; a small change in machine timing and the interrupt is handled gracefully by reporting failure to the caller. [sf-startdaemon-debug] 08/10/28 13:15:07 [Thread-6] WARN util.Shell : Interrupted while reading the error stream [sf-startdaemon-debug] java.lang.InterruptedException [sf-startdaemon-debug] at java.lang.Object.wait(Native Method) [sf-startdaemon-debug] at java.lang.Thread.join(Thread.java:1143) [sf-startdaemon-debug] at java.lang.Thread.join(Thread.java:1196) [sf-startdaemon-debug] at org.apache.hadoop.util.Shell.runCommand(Shell.java:189) [sf-startdaemon-debug] at org.apache.hadoop.util.Shell.run(Shell.java:134) [sf-startdaemon-debug] at org.apache.hadoop.util.Shell$ShellCommandExecutor.execute(Shell.java:286) [sf-startdaemon-debug] at org.apache.hadoop.util.Shell.execCommand(Shell.java:338) [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.executeShellCommand(UnixUserGroupInformation.java:326) [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.getUnixUserName(UnixUserGroupInformation.java:305) [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.login(UnixUserGroupInformation.java:232) [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.login(UnixUserGroupInformation.java:275) [sf-startdaemon-debug] at org.apache.hadoop.security.UnixUserGroupInformation.login(UnixUserGroupInformation.java:257) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.setConfigurationParameters(FSNamesystem.java:426) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.initialize(FSNamesystem.java:304) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.<init>(FSNamesystem.java:290) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:165) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.innerStart(NameNode.java:226) given I am interrupting threads during their initialization, I shouldn't expect things to work. But stopping the JVM is probably inappropriate.
        Hide
        Steve Loughran added a comment -

        Intercepting System.exit() calls stops this and changes the stack to a transition to failed state instead.
        http://jira.smartfrog.org/jira/browse/SFOS-1016

        [sf-startdaemon-debug] 08/10/28 16:18:21 [Thread-305] INFO common.Storage : Image file of size 93 saved in 0 seconds.
        [sf-startdaemon-debug] 08/10/28 16:18:21 [Thread-305] ERROR namenode.FSNamesystem : FSNamesystem initialization failed.
        [sf-startdaemon-debug] java.nio.channels.ClosedByInterruptException
        [sf-startdaemon-debug] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184)
        [sf-startdaemon-debug] at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:317)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSEditLog$EditLogFileOutputStream.<init>(FSEditLog.java:128)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSEditLog.createEditLogFile(FSEditLog.java:343)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSImage.saveFSImage(FSImage.java:1030)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSDirectory.loadFSImage(FSDirectory.java:88)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.initialize(FSNamesystem.java:311)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.<init>(FSNamesystem.java:290)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:165)
        [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.innerStart(NameNode.java:226)
        [sf-startdaemon-debug] at org.apache.hadoop.util.Service.start(Service.java:188)
        [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl.innerDeploy(HadoopServiceImpl.java:479)
        [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl.access$000(HadoopServiceImpl.java:46)
        [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl$ServiceDeployerThread.execute(HadoopServiceImpl.java:628)
        [sf-startdaemon-debug] at org.smartfrog.sfcore.utils.SmartFrogThread.run(SmartFrogThread.java:279)
        [sf-startdaemon-debug] at org.smartfrog.sfcore.utils.WorkflowThread.run(WorkflowThread.java:117)
        [sf-startdaemon-debug] 08/10/28 16:18:21 [Thread-305] INFO namenode.NameNode : State change: NameNode is now FAILED

        Show
        Steve Loughran added a comment - Intercepting System.exit() calls stops this and changes the stack to a transition to failed state instead. http://jira.smartfrog.org/jira/browse/SFOS-1016 [sf-startdaemon-debug] 08/10/28 16:18:21 [Thread-305] INFO common.Storage : Image file of size 93 saved in 0 seconds. [sf-startdaemon-debug] 08/10/28 16:18:21 [Thread-305] ERROR namenode.FSNamesystem : FSNamesystem initialization failed. [sf-startdaemon-debug] java.nio.channels.ClosedByInterruptException [sf-startdaemon-debug] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184) [sf-startdaemon-debug] at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:317) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSEditLog$EditLogFileOutputStream.<init>(FSEditLog.java:128) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSEditLog.createEditLogFile(FSEditLog.java:343) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSImage.saveFSImage(FSImage.java:1030) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSDirectory.loadFSImage(FSDirectory.java:88) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.initialize(FSNamesystem.java:311) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.<init>(FSNamesystem.java:290) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.initialize(NameNode.java:165) [sf-startdaemon-debug] at org.apache.hadoop.hdfs.server.namenode.NameNode.innerStart(NameNode.java:226) [sf-startdaemon-debug] at org.apache.hadoop.util.Service.start(Service.java:188) [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl.innerDeploy(HadoopServiceImpl.java:479) [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl.access$000(HadoopServiceImpl.java:46) [sf-startdaemon-debug] at org.smartfrog.services.hadoop.components.cluster.HadoopServiceImpl$ServiceDeployerThread.execute(HadoopServiceImpl.java:628) [sf-startdaemon-debug] at org.smartfrog.sfcore.utils.SmartFrogThread.run(SmartFrogThread.java:279) [sf-startdaemon-debug] at org.smartfrog.sfcore.utils.WorkflowThread.run(WorkflowThread.java:117) [sf-startdaemon-debug] 08/10/28 16:18:21 [Thread-305] INFO namenode.NameNode : State change: NameNode is now FAILED
        Hide
        dhruba borthakur added a comment -

        > ClosedByInterruptException get handled differently as some form of shutdown request
        This is closest to what we currently have in the NameNode.

        > Hosting a Namenode in a security manager that blocks off System.exit()
        A Security Manager imposes additional performance overhead, doesn't it?

        Show
        dhruba borthakur added a comment - > ClosedByInterruptException get handled differently as some form of shutdown request This is closest to what we currently have in the NameNode. > Hosting a Namenode in a security manager that blocks off System.exit() A Security Manager imposes additional performance overhead, doesn't it?
        Hide
        Steve Loughran added a comment -

        >> Hosting a Namenode in a security manager that blocks off System.exit()
        >A Security Manager imposes additional performance overhead, doesn't it?

        I've moved to the security manager hosting; it doesn't impose much of an overhead as only permissions for System.exit() are checked and intercepted.

        It's still a bit odd killing the process if startup fails, however, as if you run <junit fork="true"/> your process gets killed. In ant, <junit fork="false" /> runs under a security manager purely to stop anyone calling System.exit() in their code.

        Show
        Steve Loughran added a comment - >> Hosting a Namenode in a security manager that blocks off System.exit() >A Security Manager imposes additional performance overhead, doesn't it? I've moved to the security manager hosting; it doesn't impose much of an overhead as only permissions for System.exit() are checked and intercepted. It's still a bit odd killing the process if startup fails, however, as if you run <junit fork="true"/> your process gets killed. In ant, <junit fork="false" /> runs under a security manager purely to stop anyone calling System.exit() in their code.
        Hide
        Steve Loughran added a comment -

        closing as so out of date it probably doesn't happen -and if it does, the stack trace is obsolete

        Show
        Steve Loughran added a comment - closing as so out of date it probably doesn't happen -and if it does, the stack trace is obsolete

          People

          • Assignee:
            Unassigned
            Reporter:
            Steve Loughran
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development