-1

I have a Django view which runs a sub process and returns a JsonResponse back to the user:

def process_images(request, id):
    log.debug("Processing images view...")
    start = perf_counter()
    result = subprocess.run(["ssh", "<REMOTE SERVER>", "bash", "process_images.sh"],
        capture_output = True,
        text = True) # Run backend processing
        
    log.debug("Result stdout:\n" + result.stdout)
    
    with open(f"{settings.MEDIA_ROOT}/{id}/image.json", "r") as f:
        response_data = json.load(f)
        
    time_took = perf_counter() - start
    log.debug(f"View time took {time_took} seconds")
    return JsonResponse(response_data, status=201)

urls.py

from django.urls import path
from . import views

urlpatterns = [
    path('', views.index, name='index'),
    path('<id>/process', views.process_images, name='process'),
    path('<id>/', views.model, name='model')
]

app_name = "render"

However when I try accessing render/ID/process ONCE, I'm greeted with:

[Oct 25, 2022 07:30:13 PM] DEBUG [render.views:49] Processing images view...
[Oct 25, 2022 07:31:24 PM] DEBUG [render.views:55] Result stdout:
Backend processing...

[Oct 25, 2022 07:31:24 PM] DEBUG [render.views:61] View time took 70.49786422774196 seconds
[Oct 25, 2022 07:31:24 PM] DEBUG [render.views:49] Processing images view...
[Oct 25, 2022 07:32:16 PM] DEBUG [render.views:55] Result stdout:
Backend processing...
[Oct 25, 2022 07:32:16 PM] DEBUG [render.views:61] View time took 52.54661420173943 seconds
[Oct 25, 2022 07:32:16 PM] DEBUG [render.views:49] Processing images view...
[Oct 25, 2022 07:33:08 PM] DEBUG [render.views:55] Result stdout:
Backend processing...

[Oct 25, 2022 07:33:08 PM] DEBUG [render.views:61] View time took 51.900153297930956 seconds

before it finally returns the expected JsonResponse (showing that the view was called multiple times).

However, if I reduce the backend processing so that it is much faster, and then visit it again, I only get the following output:

[Oct 25, 2022 07:42:41 PM] DEBUG [render.views:49] Processing images view...
[Oct 25, 2022 07:42:44 PM] DEBUG [render.views:55] Result stdout:
Backend processing...

[Oct 25, 2022 07:42:44 PM] DEBUG [render.views:61] View time took 3.0603290796279907 seconds

where it is only called once (as expected), and with the appropriate JsonResponse.

Question: How can I ensure that the view is only called once despite large execution times?

  • I would rather not use Celery or any other libraries/schedulers to aid with offline/asynchronous views

I looked at this question, but the only answer to it is specific to that question.

Chris
  • 1,206
  • 2
  • 15
  • 35
  • 2
    This is not a problem with your code. Something is actually requesting that url more than once. Perhaps an impatient user is getting frustrated and clicking the reload button on their browser, thus sending another request. – John Gordon Oct 26 '22 at 00:25
  • @JohnGordon that's entirely possible as I'm using the production environment (can't use developmental one right now), but I didn't think that was the case because it only occurs when my backend processing code takes a long time, and I don't see any other logging messages any other time besides that. Also in that case, wouldn't the code inside the view just stop executing? – Chris Oct 26 '22 at 00:29
  • It makes logical sense, because if the url takes only a few seconds to respond, that's not enough time for a user to get frustrated and decide to click the reload button. And no, the code would not just stop executing. – John Gordon Oct 26 '22 at 00:33
  • I changed my logging so that it displays the id as well (I have it set to a randomised id like the ones YouTube uses), and I know no one else has knowledge of that, and I know I'm not refreshing the page, so I'm pretty sure that isn't the problem – Chris Oct 26 '22 at 00:58
  • Look at the webserver access log, and see where the requests to that url come from. – John Gordon Oct 26 '22 at 00:59
  • It says all the requests are coming from me, but I'm not refreshing or closing any of the tabs – Chris Oct 26 '22 at 01:19
  • You're simply looking in the wrong place, you have to look at your frontend code and see where it's making those calls from. – Abdul Aziz Barkat Oct 27 '22 at 04:09
  • @AbdulAzizBarkat I'm simply visiting the /render//process url of my website which only returns a JsonResponse, there are no other redirects – Chris Oct 27 '22 at 14:20
  • How do you hit this url? Test it out using Postman, do you still get the logs repeated? – Abdul Aziz Barkat Oct 27 '22 at 14:27
  • @AbdulAzizBarkat I'm not sure what that is, but that still seems irrelevant given the fact that it only repeats when the backend processing time is long - it seems like ssh and subprocess.run() are the problem – Chris Nov 02 '22 at 14:00

1 Answers1

0

While I don't understand the source for this error, I was able to avoid it by using subprocess.Popen rather than subprocess.run, so that it could run it in the background and immediately return the view (avoiding the long execution time):

def process_images(request, id):
    result = subprocess.Popen(["ssh", "<REMOTE SERVER>",
                               "bash", "process_images.sh"]) # UPDATED LINE   
        
    return JsonResponse({}, status=201)

I then used ajax requests to check if the backend processing had finished, and returned the results there.

Chris
  • 1,206
  • 2
  • 15
  • 35