Duplicate FD close in storlet-gateway

[Akihito Takai]

we found that storlet_gateway duplicates following FD close.
storlets PUT request: self.execution_str_write_fd, self.data_write_fd, self.metadata_write_fd, self._input_data_read_fd
storlets GET request: self.execution_str_write_fd, self.data_write_fd, self.metadata_write_fd

・examination method

①Add logger.info

storlet_gateway/gateways/docker/runtime.py
...
    def _prepare_invocation_descriptors(self):
        """
        Create all pipse used for Storlet execution
        """
        if not self.srequest.has_fd:
            self._input_data_read_fd, self._input_data_write_fd = os.pipe()
            self.logger.info("self._input_data_read_fd=%s, self._input_data_write_fd=%s" <-------- Add
                            % (self._input_data_read_fd, self._input_data_write_fd)) <-------- Add
        self.data_read_fd, self.data_write_fd = os.pipe()
        self.logger.info("self.data_read_fd=%s, self.data_write_fd=%s" <-------- Add
                        % (self.data_read_fd, self.data_write_fd)) <-------- Add
        self.execution_str_read_fd, self.execution_str_write_fd = os.pipe()
        self.logger.info("self.execution_str_read_fd=%s, self.execution_str_write_fd=%s" <-------- Add
                        % (self.execution_str_read_fd, self.execution_str_write_fd)) <-------- Add
        self.metadata_read_fd, self.metadata_write_fd = os.pipe()
        self.logger.info("self.metadata_read_fd=%s, self.metadata_write_fd=%s" <-------- Add
                        % (self.metadata_read_fd, self.metadata_write_fd)) <-------- Add

        for source in self.extra_data_sources:
            source['read_fd'], source['write_fd'] = os.pipe()

    def _safe_close(self, fds):
        """
        Make sure that all of the file descriptors get closed

        :param fds: a list of file descriptors
        """
        for fd in fds:
            try:
                os.close(fd)
            except OSError as err:
                self.logger.info("fd(%s) close error = %s" % (fd, err)) <-------- Add
                if err.errno != errno.EBADF:
                    raise
                # TODO(kota_): fd might be closed already, so if already
                # closed, OSError will be raised. we need more refactor to
                # keep clean the file discriptors.
                pass
...

② Do storlets request and check log

・GET request
# curl -H 'X-Auth-Token: XXXXXXXXXXXXX' -v -X GET http://127.0.0.1:80/v1/AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects/test_object -o ~/output -H 'X-Run-Storlet: simple.py'

/var/log/swift/object-server.log
object-server: 127.0.0.1 - - [20/Oct/2016:02:13:08 +0000] "HEAD /loop0/119466/AUTH_XXXXXXXXXXXXXXXXXXXX/storlet/simple.py" 200 1570 "HEAD http://127.0.0.1/v1/AUTH_XXXXXXXXXXXXXXXXXXXX/storlet/simple.py" "tx734e22184e1d443ab7d5c-0058082834" "proxy-server 29694" 0.0052 "-" 29693 0
object-server: storlet_handler call in object: with AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects/test_object
object-server: GET. Run storlet
object-server: 127.0.0.1 - - [20/Oct/2016:02:13:08 +0000] "GET /loop0/209056/AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects/test_object" 200 12 "GET http://127.0.0.1/v1/AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects/test_object" "tx734e22184e1d443ab7d5c-0058082834" "proxy-server 29694" 0.0019 "-" 29693 0
object-server: Verify if AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects/test_object is an SLO assembly object (txn: tx734e22184e1d443ab7d5c-0058082834)
object-server: AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects/test_object is NOT an SLO assembly object (txn: tx734e22184e1d443ab7d5c-0058082834)
object-server: storlet_handler: invocation over AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects/test_object to be executed locally (txn: tx734e22184e1d443ab7d5c-0058082834)
object-server: self.data_read_fd=13, self.data_write_fd=14 (txn: tx734e22184e1d443ab7d5c-0058082834)
object-server: self.execution_str_read_fd=15, self.execution_str_write_fd=16 (txn: tx734e22184e1d443ab7d5c-0058082834)
object-server: self.metadata_read_fd=17, self.metadata_write_fd=18 (txn: tx734e22184e1d443ab7d5c-0058082834)
object-server: fd(14) close error = [Errno 9] Bad file descriptor (txn: tx734e22184e1d443ab7d5c-0058082834)
object-server: fd(18) close error = [Errno 9] Bad file descriptor (txn: tx734e22184e1d443ab7d5c-0058082834)
object-server: fd(16) close error = [Errno 9] Bad file descriptor (txn: tx734e22184e1d443ab7d5c-0058082834)

・PUT request
# curl -H 'X-Auth-Token: XXXXXXXXXXXXX' -v -X PUT http://127.0.0.1:80/v1/AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects/test_object_2 -T ~/obj -H 'X-Run-Storlet: simple.py'

/var/log/swift/proxy-server.log
proxy-server: Deferring reject downstream
proxy-server: - - 20/Oct/2016/02/21/30 HEAD /v1/AUTH_XXXXXXXXXXXXXXXXXXXX HTTP/1.0 204 - Swift - - - - tx6573c94362f446d6931a9-0058082a2a - 0.0157 RL - 1476930090.726922035 1476930090.742618084 -
proxy-server: Deferring reject downstream
proxy-server: - - 20/Oct/2016/02/21/30 HEAD /v1/AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects HTTP/1.0 204 - Swift - - - - tx6573c94362f446d6931a9-0058082a2a - 0.0148 RL - 1476930090.746170044 1476930090.760936975 0
proxy-server: - - 20/Oct/2016/02/21/30 HEAD /v1/AUTH_XXXXXXXXXXXXXXXXXXXX/storlet/simple.py HTTP/1.0 200 - Swift 19586f10975f4f2c... - - - tx6573c94362f446d6931a9-0058082a2a - 0.0256 ST - 1476930090.765764952 1476930090.791366100 0
proxy-server: self._input_data_read_fd=25, self._input_data_write_fd=26 (txn: tx6573c94362f446d6931a9-0058082a2a)
proxy-server: self.data_read_fd=27, self.data_write_fd=28 (txn: tx6573c94362f446d6931a9-0058082a2a)
proxy-server: self.execution_str_read_fd=29, self.execution_str_write_fd=30 (txn: tx6573c94362f446d6931a9-0058082a2a)
proxy-server: self.metadata_read_fd=31, self.metadata_write_fd=32 (txn: tx6573c94362f446d6931a9-0058082a2a)
proxy-server: fd(28) close error = [Errno 9] Bad file descriptor (txn: tx6573c94362f446d6931a9-0058082a2a)
proxy-server: fd(32) close error = [Errno 9] Bad file descriptor (txn: tx6573c94362f446d6931a9-0058082a2a)
proxy-server: fd(30) close error = [Errno 9] Bad file descriptor (txn: tx6573c94362f446d6931a9-0058082a2a)
proxy-server: fd(25) close error = [Errno 9] Bad file descriptor (txn: tx6573c94362f446d6931a9-0058082a2a)
proxy-server: 127.0.0.1 127.0.0.1 20/Oct/2016/02/21/36 PUT /v1/AUTH_XXXXXXXXXXXXXXXXXXXX/myobjects/test_object_2 HTTP/1.0 201 - curl/7.35.0 19586f10975f4f2c... 10485760 - - tx6573c94362f446d6931a9-0058082a2a - 5.3979 - - 1476930090.723591089 1476930096.121486902 0

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/389041

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/389041
Committed: https://git.openstack.org/cgit/openstack/storlets/commit/?id=e398d032c8c1597aad128237a8c8419af55395b1
Submitter: Jenkins
Branch: master

commit e398d032c8c1597aad128237a8c8419af55395b1
Author: Akihito Takai <email address hidden>
Date: Thu Oct 20 16:26:34 2016 +0900

    Fix duplication of FD close in storlet_gateway

    storlet_gateway duplicates following FD close now.(all remote side FD)

    storlets PUT request: self.execution_str_write_fd, self.data_write_fd,
                          self.metadata_write_fd, self._input_data_read_fd
    storlets GET request: self.execution_str_write_fd, self.data_write_fd,
                          self.metadata_write_fd

    Because "_close_remote_side_descriptors" is called twice.

    This patch modifies the called "_close_remote_side_descriptors" to once.

    Change-Id: I60c537a6747fdff678bfe998ccb5bebf77ac37a0
    Closes-Bug: #1635088