Torch.cuda.empty_cache() very very slow performance
I have a very slow performance problem when I execute an inference batch loop on a single GPU.
This slow behavior appears after the first batch has been processed -
that is when the GPU is already almost full and its memory needs to be recycled to accept the next batch.
At a pristine GPU state - the performance is super fast (as expected).
I hope both the following code snippet and the output illustrate the problem in a nutshell.
(I've removed the print and time measurements from the snippet for brevity)
predictions = None

for i, batch in enumerate(self.test_dataloader):

    # if this line is active - the bottleneck after the first batch moves here, rather than below
    # i.e. when i &gt; 0
    # torch.cuda.empty_cache()    

    # HUGE PERFORMANCE HIT HAPPENS HERE - after the first batch
    # i.e. when i &gt; 0
    # obviously tensor.to(device) uses torch.cuda.empty_cache() internally when needed
    # and it is inexplicably SLOW
    batch = tuple(t.to(device) for t in batch)  # to GPU (or CPU) when gpu

    b_input_ids, b_input_mask, b_labels = batch

    with torch.no_grad():
        outputs = model(b_input_ids, token_type_ids=None, attention_mask=b_input_mask)

    logits = outputs[0]
    logits = logits.detach()

    # that doesn't help alleviate the issue
    del outputs

    predictions = logits if predictions is None else torch.cat((predictions, logits), 0)            

    # nor do all of the below - freeing references doesn't help speeding up
    del logits
    del b_input_ids
    del b_input_mask
    del b_labels
    for o in batch:
        del o
    del batch



output
start empty cache... 0.00082
end empty cache... 1.9e-05
start to device... 3e-06
end to device... 0.001179 - HERE - time is super fast (as expected)
start outputs... 8e-06
end outputs... 0.334536
logits... 6e-06
start detach... 1.7e-05
end detach... 0.004036

start empty cache... 0.335932
end empty cache... 4e-06
start to device... 3e-06
end to device... 16.553849 - HERE - time is ridiculously high - it's 16 seconds to move tensor to GPU
start outputs... 2.3e-05
end outputs... 0.020878
logits... 7e-06
start detach... 1.4e-05
end detach... 0.00036

start empty cache... 0.00082
end empty cache... 6e-06
start to device... 4e-06
end to device... 17.385204 - HERE - time is ridiculously high
start outputs... 2.9e-05
end outputs... 0.021351
logits... 4e-06
start detach... 1.3e-05
end detach... 1.1e-05

...


Have I missed something obvious or is this the expected GPU behavior?
I am posting this question before engaging in complex coding, juggling between a couple of GPUs and CPU available on my server.
Thanks in advance,
Albert
EDIT
RESOLVED The issue was: in DataLoader constructor - I changed the pin_memory to False (True was causing the issue). That cut the .to(device) time by 350%-400%
self.test_dataloader = DataLoader(
            test_dataset,
            sampler=SequentialSampler(test_dataset),
            # batch_size=len(test_dataset)  # AKA - single batch - nope! no mem for that
            batch_size=BATCH_SIZE_AKA_MAX_ROWS_PER_GUESS_TO_FIT_GPU_MEM,
            # tests
            num_workers=8,
            # maybe this is the culprit as suggested by user12750353 in stackoverflow
            # pin_memory=True
            pin_memory=False
        )


You should not be required to clear cache if you are properly clearing the references to the previously allocated variables. Cache is like free, is memory that your script can use for new variables.
Also notice that
a = torch.zeros(10**9, dtype=torch.float)
a = torch.zeros(10**9, dtype=torch.float)

Requires 8GB of memory, even though a uses 4GB (1B elements with 4 bytes each). This occurs because the torch.zeros will allocate memory before the previous content of a is released. This may be happening in your model in a larger scale, depending on how it is implemented.
Edit 1
One suspicious thing is that you are loading your batch to the GPU one example at a time.
Just to illustrate what I mean
import torch
device = 'cuda'
batch = torch.zeros((4500, 10));

Creating the batch as a tuple
batch_gpu = tuple(t.to(device) for t in batch) 
torch.cuda.synchronize()

254 ms ± 36 ms per loop (mean ± std. dev. of 7 runs, 1 loop each)
Creating the batch as a list
batch_gpu = list(t.to(device) for t in batch) 
torch.cuda.synchronize()

235 ms ± 3.74 ms per loop (mean ± std. dev. of 7 runs, 1 loop each)
batch_gpu = batch.to(device)
torch.cuda.synchronize()

115 µs ± 2.9 µs per loop (mean ± std. dev. of 7 runs, 10000 loops each)
In this example it was 2000x faster to copy one example at a time.
Notice that GPU works asynchronously with the CPU. So you may keep calling functions that will return before the operation is finished. In order to make meaningful measurements you may call synchronize to make clear the time boundaries.
The code to be instrumented is this
for i, batch in enumerate(self.test_dataloader):

    # torch.cuda.empty_cache()    
    # torch.synchronize() # if empty_cache is used
    

    # start timer for copy
    batch = tuple(t.to(device) for t in batch)  # to GPU (or CPU) when gpu
    torch.cuda.synchronize()
    # stop timer for copy

    b_input_ids, b_input_mask, b_labels = batch

    # start timer for inference
    with torch.no_grad():
        outputs = model(b_input_ids, token_type_ids=None, attention_mask=b_input_mask)
    torch.cuda.synchronize()
    # stop timer for inference


    logits = outputs[0]
    logits = logits.detach()
    # if you copy outputs to CPU it will be synchronized


