Context Deadline is not cancelling a go routine fuction unless I reduce deadline

Question

I modified a function from a book I was reading, the function writes "ping" to a writer at a predefined interval. The program runs in a go routine so I appended a context so the function can return once the context deadline exceeds. However, the function doesnt return unless I set the initial interval to 4 seconds or less.

package pinge

import (
    "context"
    "fmt"
    "io"
    "time"
)

const defaultInterval = time.Second * 15
func Pinger(ctx context.Context, w io.Writer, durChan <-chan time.Duration) (count int, err error) {
    interval := defaultInterval
    count = 0

    select {
    case <-ctx.Done():
        return count, ctx.Err()
    case interval = <-durChan:
        if interval <= 0 {
            interval = defaultInterval
        }
    default:
    }

    t := time.NewTimer(interval)
    defer func() {
        if !t.Stop() {
            <-t.C
        }
    }()

    for {
        select {
        case <-ctx.Done():
            fmt.Println("Deadline exceeded")
            return count, ctx.Err()
        case newInterval := <-durChan:
            if newInterval > 0 {
                interval = newInterval
            }
            if !t.Stop() {
                <-t.C
            }
        case <-t.C:
            if _, err := w.Write([]byte("ping")); err != nil {
                return count, err
            }
            count++
        }
        t.Reset(interval)
    }
}

I wrote a test script to test the function but it keeps timing out because the test did not return in the 30s timeout frame. Here is my test func

func TestPinger(t *testing.T) {

    ddl := time.Now().Add(time.Second * 10)
    initInterval := time.Second * 2
    countChan := make(chan int)
    durChan := make(chan time.Duration, 1)
    doneChan := make(chan struct{})


    ctx, cancelCtx := context.WithDeadline(context.Background(), ddl)
    defer cancelCtx()

    r, w := io.Pipe()

    durChan <- initInterval

    go func() {
        count, err := Pinger(ctx, w, durChan)
        countChan <- count
        if err != nil {
            doneChan <- struct{}{}
        }
    }()

    buf := make([]byte, 1024)

    n, err := r.Read(buf)
    if err != nil {
        t.Error("Could not read buffer: ", err)
    }

    fmt.Printf("Received: %q\n", buf[:n])

    var pingCount int

    select {
    case <- doneChan: 
        fmt.Println("Ping Count =", pingCount)
        return
    case pingCount = <-countChan:
    }
    fmt.Println("Ping Count =", pingCount)
}

Answer 1

The reason code hangs is because you read only once (ie the first Write) from the pipe. Documentation of the pipe says:

Reads and Writes on the pipe are matched one to one except when multiple Reads are needed to consume a single Write. That is, each Write to the PipeWriter blocks until it has satisfied one or more Reads from the PipeReader that fully consume the written data.

So in the code the TestPinger func will block on line

n, err := r.Read(buf)

until timer fires in the Pinger and w.Write([]byte("ping")) is executed - that causes the Read func to return and next it blocks on the select statement. However, in the Pinger when the timer fires again it now gets stuck on the w.Write as there is no-one reading from the pipe... so the loop is stuck there and thus doesn't have opportunity to see that the context has expired.

Fix: Send WriteCloser to the Pinger and close the w on exit:

func Pinger(ctx context.Context, w io.WriteCloser, durChan <-chan time.Duration) (count int, err error) {
    defer w.Close()

and in the main func read until EOF, ie:

    buf := bytes.NewBuffer(nil)

    _, err := io.Copy(buf, r)
    if err != nil {
        t.Error("Could not read buffer: ", err)
    }

    fmt.Printf("Received: %q\n", buf.String())