Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Serious memory leak on multipart file upload #929

Closed
mykola-mokhnach opened this issue Jun 15, 2020 · 11 comments · Fixed by #930
Closed

Serious memory leak on multipart file upload #929

mykola-mokhnach opened this issue Jun 15, 2020 · 11 comments · Fixed by #930
Assignees

Comments

@mykola-mokhnach
Copy link
Contributor

Hello,

it looks like there is a series memory leak while uploading multipart files to s3 using this client. We use version 5.0.10 of it and were observing constant pod crashes due to OutOfMemory exceptions while uploading bigger files to S3. This is particularly visible if the allocated amount of pod memory resources is low. After some investigation we've figured out the root cause of the issue might be in

part_data = read_full(data, current_part_size)
:

        for part_number in range(1, total_parts_count + 1):
            current_part_size = (part_size if part_number < total_parts_count
                                 else last_part_size)

            part_data = read_full(data, current_part_size)
            pool.add_task(self._upload_part_routine, (
                bucket_name, object_name, upload_id, part_number, part_data,
                sse, progress))

In this loop we load the data from the source and put the chunks into the pool. The actual cause is the part_data = read_full(data, current_part_size) line. We, actually, load all the chunks into RAM first (even for very big files) and pass these memory chunks into corresponding upload threads. I assume the expected behaviour should be that the data should be read into the memory from the inside of each thread. This way only the "active" chunks will be loaded into RAM when the pool decides to activate the particular thread (according to its max_workers setting).

Some local debugging to illustrate the issue better:

DEBUG:2020-06-15 18:14:40,582: Current memory usage by the process: 47.465 MiB of 435.200 MiB
DEBUG:MinIO Client:2020-06-15 18:14:40,588: Got request for "500M.dat" file upload
INFO:Progress:2020-06-15 18:14:40,590: !!! Memory usage before preload: 47.465 MiB
DEBUG:urllib3.connectionpool:http://service-minio.default.svc.cluster.local:9000 "POST /testbucket/app-storage/6323d357-d363-418b-8a93-415e13c612cc?uploads= HTTP/1.1" 200 None
DEBUG:urllib3.connectionpool:Starting new HTTP connection (2): service-minio.default.svc.cluster.local:9000
DEBUG:urllib3.connectionpool:http://service-minio.default.svc.cluster.local:9000 "PUT /testbucket/app-storage/6323d357-d363-418b-8a93-415e13c612cc?partNumber=1&uploadId=f8d5f2b8-5e3a-46ba-bdf4-696384633e46 HTTP/1.1" 200 0
INFO:Progress:2020-06-15 18:14:48,067: !!! Memory usage after preload: 422.996 MiB
DEBUG:urllib3.connectionpool:http://service-minio.default.svc.cluster.local:9000 "PUT /testbucket/app-storage/6323d357-d363-418b-8a93-415e13c612cc?partNumber=2&uploadId=f8d5f2b8-5e3a-46ba-bdf4-696384633e46 HTTP/1.1" 200 0
INFO:Progress:2020-06-15 18:14:48,469: !!! Memory usage after preload: 369.555 MiB
DEBUG:urllib3.connectionpool:http://service-minio.default.svc.cluster.local:9000 "PUT /testbucket/app-storage/6323d357-d363-418b-8a93-415e13c612cc?partNumber=3&uploadId=f8d5f2b8-5e3a-46ba-bdf4-696384633e46 HTTP/1.1" 200 0
INFO:Progress:2020-06-15 18:14:53,871: !!! Memory usage after preload: 397.773 MiB
DEBUG:urllib3.connectionpool:http://service-minio.default.svc.cluster.local:9000 "PUT /testbucket/app-storage/6323d357-d363-418b-8a93-415e13c612cc?partNumber=4&uploadId=f8d5f2b8-5e3a-46ba-bdf4-696384633e46 HTTP/1.1" 200 0
INFO:Progress:2020-06-15 18:14:54,098: !!! Memory usage after preload: 322.770 MiB
DEBUG:urllib3.connectionpool:http://service-minio.default.svc.cluster.local:9000 "PUT /testbucket/app-storage/6323d357-d363-418b-8a93-415e13c612cc?partNumber=5&uploadId=f8d5f2b8-5e3a-46ba-bdf4-696384633e46 HTTP/1.1" 200 0
INFO:Progress:2020-06-15 18:14:58,260: !!! Memory usage after preload: 247.766 MiB
DEBUG:urllib3.connectionpool:http://service-minio.default.svc.cluster.local:9000 "PUT /testbucket/app-storage/6323d357-d363-418b-8a93-415e13c612cc?partNumber=6&uploadId=f8d5f2b8-5e3a-46ba-bdf4-696384633e46 HTTP/1.1" 200 0
INFO:Progress:2020-06-15 18:14:58,356: !!! Memory usage after preload: 172.762 MiB
DEBUG:urllib3.connectionpool:http://service-minio.default.svc.cluster.local:9000 "PUT /testbucket/app-storage/6323d357-d363-418b-8a93-415e13c612cc?partNumber=7&uploadId=f8d5f2b8-5e3a-46ba-bdf4-696384633e46 HTTP/1.1" 200 0
INFO:Progress:2020-06-15 18:14:59,530: !!! Memory usage after preload: 97.738 MiB
DEBUG:urllib3.connectionpool:http://service-minio.default.svc.cluster.local:9000 "POST /testbucket/app-storage/6323d357-d363-418b-8a93-415e13c612cc?uploadId=f8d5f2b8-5e3a-46ba-bdf4-696384633e46 HTTP/1.1" 200 None

The callback that displays the memory usage was put into the Progress thread (set_meta and update methods). The memory usage is measured using psutil module (the RSS value)

@harshavardhana
Copy link
Member

what is the actual memory limit on the pods ? @mykola-mokhnach can you share the application code here?

@mykola-mokhnach
Copy link
Contributor Author

mykola-mokhnach commented Jun 15, 2020

The application code is super straightforward. This method is uploading files:

PART_SIZE = 75 * MiB
...

    def upload_file(self, src_path: str, progress: threading.Thread = None) -> FileStat:
        file_id = str(uuid.uuid4())
        file_name = os.path.basename(src_path)
        log.debug(f'Got request for "{file_name}" file upload, uuid: {file_id}')
        self._require_client().fput_object(bucket_name=self._config.bucket,
                                           object_name=STORAGE_ROOT + file_id,
                                           file_path=src_path,
                                           progress=progress,
                                           part_size=PART_SIZE)
        log.debug(f'"{file_name}" has been successfully uploaded, uuid: {file_id}')
        return self.stat_file(file_id)

The memory limit on the pod is 512M, the size of the file is 500M

@harshavardhana
Copy link
Member

PART_SIZE = 75 * MiB

At max it should use 75*(num_workers) @mykola-mokhnach do you see beyond this?

@mykola-mokhnach
Copy link
Contributor Author

This is what I would expect as well. I see the default workers count is 3. But you see the actual allocation value in the log - it's much bigger than that

@harshavardhana
Copy link
Member

This is what I would expect as well. I see the default workers count is 3. But you see the actual allocation value in the log - it's much bigger than that

That I think looks like because the buffer is not re-used - although it is still using 225MiB per 3 workers.

@mykola-mokhnach
Copy link
Contributor Author

75*3=225 would be fine, but it shows 423 :(

@mykola-mokhnach
Copy link
Contributor Author

I looks like the issue also exists for single-part uploads. In

current_data = data.read(length)
the lib also loads the content of the file fully into RAM. I have no idea why it is done this way, since urllib3 can perfectly deal with file handles passed as body argument.

For now I've rewritten the implementation like that in my client code. It only supports single-part file upload, but this is fine with us, since the max file size is limited to 4GB (Amazon's high limit is 5GB per part). The average memory usage of such code snippet is no more than 5 MB:

def load_file_hash(hash_func, file_path: str):
    with open(file_path, 'rb') as f:
        while True:
            chunk = f.read(1 * MiB)
            if not chunk:
                break
            hash_func.update(chunk)
    return hash_func

...

    def upload_file(self, src_path: str, progress: Optional[Progress] = None) -> FileStat:
        file_id = str(uuid.uuid4())
        file_name = os.path.basename(src_path)
        log.debug(f'Got request for "{file_name}" file upload, uuid: {file_id}')

        # A workaround for https://github.com/minio/minio-py/issues/929
        total_size = os.stat(src_path).st_size
        headers = {
            'Content-Length': str(total_size),
        }
        md5_base64 = ''
        sha256_hex = _UNSIGNED_PAYLOAD
        if self._config.secure:
            h = load_file_hash(hashlib.md5(), src_path)
            md5_base64 = base64.b64encode(h.digest()).decode('utf-8')
        else:
            h = load_file_hash(hashlib.sha256(), src_path)
            sha256_hex = h.hexdigest()
        if md5_base64:
            headers['Content-Md5'] = md5_base64
        if progress:
            progress.set_meta(total_size, STORAGE_ROOT + file_id)
        with open(src_path, 'rb') as body:
            # noinspection PyProtectedMember
            self._require_client()._url_open(
                'PUT',
                bucket_name=self._config.bucket,
                object_name=STORAGE_ROOT + file_id,
                headers=headers,
                body=body,
                content_sha256=sha256_hex
            )
        if progress:
            progress.update(total_size)

        log.debug(f'"{file_name}" has been successfully uploaded, uuid: {file_id}')
        return self.stat_file(file_id)

@vadmeste
Copy link
Member

@mykola-mokhnach this is not a memory leak. The maximum allocated memory would be 6 x part_size, but I also sent a PR which reduces the memory usage.

@mykola-mokhnach
Copy link
Contributor Author

Thanks for your response @vadmeste

Could you please answer some more questions if you have time?

  • Was this a deliberate decision to load parts fully into the memory?
  • The maximum size of single part could be up to 5 GB - would this be a safe solution? Is 6 x part_size rule documented anywhere?

@vadmeste
Copy link
Member

  • Was this a deliberate decision to load parts fully into the memory?

The data source is a stream, and the S3 spec requires that we know that size of the data before uploading it.. so we don't have a choice here.

  • The maximum size of single part could be up to 5 GB - would this be a safe solution? Is 6 x part_size rule documented anywhere?

Not safe, but the default part size is 5 Mb anyway, we can't do much AFAIK

@mykola-mokhnach
Copy link
Contributor Author

The data source is a stream, and the S3 spec requires that we know that size of the data before uploading it.. so we don't have a choice here.

I probably don't know much about the original background there. These are just some ideas on how I would optimize the stuff:

  • the fput_object primitive accepts file paths, which means it is possible to create multiple streams from it and calculate hashes without loading the stuff fully into the memory.
  • for the put_object method, where we accept io.RawIOBase instance we could use the local file system as a buffer. The probability one has several hundreds megabytes of extra space on his file system is much higher than in the RAM. Also, the process memory is limited to 4GB (in reality even less) is 32-bit interpreter is used

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants