Duke-GCB/calrissian

KubernetesClient.follow_logs() exits before getting all logs

Closed this issue · 2 comments

follow_logs was added in #59, and calls read_namespaced_pod_log() with follow=True.

In my tests of the GATK4 preprocessing workflow, I can see that the generator returned by stream() finishes while the pod is still running.

logs from calrissian job:

$ oc logs --timestamps=True job/calrissian-gatk4-preprocessing |grep trim-pod
2019-03-14T18:52:27.643057398Z [trim-pod-klhihztw] 2019-03-14T18:52:28.377254055Z   >>> Now performing quality (cutoff 20) and adapter trimming in a single pass for the adapter sequence: 'AGATCGGAAGAGC' from file /var/lib/cwl/stg5811d013-3646-40db-9308-efdf548c1776/SA05051-R2.fastq.gz <<<
2019-03-14T18:58:30.490922326Z [trim-pod-klhihztw] 2019-03-14T18:58:31.219549578Z 10000000 sequences processed
2019-03-14T19:04:36.760504315Z [trim-pod-klhihztw] 2019-03-14T19:04:37.48981895Z 20000000 sequences processed
2019-03-14T19:10:50.103854762Z [trim-pod-klhihztw] 2019-03-14T19:10:50.83159839Z 30000000 sequences processed
2019-03-14T19:17:27.807121329Z [trim-pod-klhihztw] 2019-03-14T19:17:28.540569252Z 40000000 sequences processed
2019-03-14T19:22:32.967763539Z [trim-pod-klhihztw] follow_logs end

logs directly from the pod

$ oc logs --timestamps trim-pod-klhihztw
2019-03-14T18:52:28.377254055Z   >>> Now performing quality (cutoff 20) and adapter trimming in a single pass for the adapter sequence: 'AGATCGGAAGAGC' from file /var/lib/cwl/stg5811d013-3646-40db-9308-efdf548c1776/SA05051-R2.fastq.gz <<< 
2019-03-14T18:58:31.219549578Z 10000000 sequences processed
2019-03-14T19:04:37.48981895Z 20000000 sequences processed
2019-03-14T19:10:50.83159839Z 30000000 sequences processed
2019-03-14T19:17:28.540569252Z 40000000 sequences processed
2019-03-14T19:22:33.692899536Z This is cutadapt 1.14 with Python 3.5.2
2019-03-14T19:22:33.693016208Z Command line parameters: -f fastq -e 0.1 -q 20 -O 1 -a AGATCGGAAGAGC /var/lib/cwl/stg5811d013-3646-40db-9308-efdf548c1776/SA05051-R2.fastq.gz
2019-03-14T19:22:33.693031811Z Trimming 1 adapter with at most 10.0% errors in single-end mode 

The pod was running for about an hour when follow_logs exited:

2019-03-14T18:19:44.408873685Z k8s pod 'trim-pod-klhihztw' started
2019-03-14T18:19:49.311305246Z [trim-pod-klhihztw] follow_logs start
...
2019-03-14T19:22:32.967763539Z [trim-pod-klhihztw] follow_logs end

Some improvements were made in kubernetes-client/python-base#93. We're currently at 8.0 and could upgrade to take advantage of that

close by merge PR #97