AcademySoftwareFoundation / AcademySoftwareFoundation/OpenCue

No frame will run for longer than ~5 minutes

Open
#1,202 6 comments 0 reactions 0 assignees View on GitHub
bug
Dominant language
Python
Stars
957
Forks
259
Avg merge
3d 6h
Merged PRs (30d)
16

Description

Every frame that runs for longer than 5 minutes gets killed by `rqd` at 5-minutes-and-change.

I was trying to track this down in our (barely customized) fork of OpenCue, but I tested with a vanilla dockerized OpenCue and got the same result. Here's a log from that system for a frame running under `rqd`. The command is simply `/bin/sleep 1000`:
```
===========================================================
RenderQ JobSpec Fri Sep 16 14:48:13 2022

proxy rqd.rqnetwork.RunningFrame/ea49ae9f-48df-4513-82d0-3b1216dff95c -t:tcp -h 172.18.0.5 -p 10021
command /bin/sleep 1000
uid 38859
gid 20
logDestination /tmp/rqd/logs/testtwo/test_shot/logs/testtwo-test_shot-donal_helloworld5--0e4f18fd-a1ae-4277-a343-0c608eb96e65/testtwo-test_shot-donal_helloworld5.0001-test_layer.rqlog
cwd /tmp/testtwo-test_shot-donal_helloworld5/0001-test_layer
renderHost 172.18.0.5
jobId 0e4f18fd-a1ae-4277-a343-0c608eb96e65
frameId ea49ae9f-48df-4513-82d0-3b1216dff95c
env CUE3=1
env CUE_CHUNK=1
env CUE_FRAME=0001-test_layer
env CUE_FRAME_ID=ea49ae9f-48df-4513-82d0-3b1216dff95c
env CUE_GPUS=0
env CUE_GPU_MEMORY=0
env CUE_IFRAME=1
env CUE_JOB=testtwo-test_shot-donal_helloworld5
env CUE_JOB_ID=0e4f18fd-a1ae-4277-a343-0c608eb96e65
env CUE_LAYER=test_layer
env CUE_LAYER_ID=667ebc0c-73f5-4cc7-8ce8-67cc3affaf2a
env CUE_LOG_PATH=/tmp/rqd/logs/testtwo/test_shot/logs/testtwo-test_shot-donal_helloworld5--0e4f18fd-a1ae-4277-a343-0c608eb96e65
env CUE_MEMORY=3355443
env CUE_RANGE=1
env CUE_SHOT=test_shot
env CUE_SHOW=testtwo
env CUE_THREADABLE=0
env CUE_THREADS=1
env CUE_USER=donal
env HOME=/net/homedirs/donal
env LOGNAME=donal
env MAIL=/usr/mail/donal
env PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
env SP_NOMYCSHRC=1
env TERM=unknown
env TZ=PST8PDT
env USER=donal
env frame=0001-test_layer
env jobhost=172.18.0.5
env jobid=testtwo-test_shot-donal_helloworld5
env logfile=testtwo-test_shot-donal_helloworld5.0001-test_layer.rqlog
env maxframetime=0
env mcp=1
env minspace=200
env shot=test_shot
env show=testtwo
env zframe=0001-test_layer
===========================================================

===========================================================
RenderQ Job Complete

exitStatus 1
exitSignal 9
killMessage OpenCue could not verify this frame.
startTime Fri Sep 16 14:48:13 2022
endTime Fri Sep 16 14:53:59 2022
maxrss 7760
maxUsedGpuMemory 0
utime 0
stime 0
renderhost 172.18.0.5
===========================================================
```

I speculated that `rqd` is killing frames that stop producing output on stdout/stderr for some time, so mostly I've been testing with a Python script that prints out progress tokens at 10-second intervals. It fails in the same way at roughly the same time.

I can add more information (rqd and cuebot log output, etc) to the ticket, but first of all... can someone else please try to reproduce this behaviour on a standard vanilla setup?

Contributor guide

Open the contributing guide

Research direction

Reproduce the issue on a vanilla dockerized OpenCue setup using the reported `/bin/sleep 1000` command, then compare the rqd and cuebot log output around the five-minute failure. Done means identifying why the frame receives signal 9 and confirming that a frame running longer than five minutes can complete normally.

Written by the indexing model from the issue text.

Assessment

Tech stack
docker, python
Domain
backend, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
30/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.