Golang обработка сигналов и взаимодействия time.Sleep () - PullRequest
Новая
       31

Golang обработка сигналов и взаимодействия time.Sleep ()

0 голосов
/ 05 мая 2020

У меня проблемы с программой Go, которая должна улавливать SIGTERM и корректно завершать свою работу. Я вижу, что он запускает процедуру выключения, но затем внезапно завершается, не завершая процедуру выключения. Я разместил журналы в разных местах и ​​вижу, что они ничего не выводят на стандартный вывод. Вот фрагмент кода и результаты: 

    sigs := make(chan os.Signal, 1)
    signal.Notify(sigs, os.Interrupt, syscall.SIGTERM)

    select {
    case <-sigs:
        signal.Stop(sigs)
        log.Info().Msg("runsomething: SIGTERM caught")
        close(stopC)
        cancel()
        log.Info().Msg("Stopping all goroutines")

        // This sleep doesn't have any effect when shutdown via SIGTERM
        time.Sleep(time.Second * 2)
        log.Info().Msg("THIS SHOULD PRINT, WHY DOESNT IT?")
    case <-doneC:
    }

    // This sleep doesn't have any effect when shutdown via SIGTERM nor
    // does the following log print
    time.Sleep(time.Second * 2)
    log.Info().Msg("runsomething: DONE")

Вот результат нормального завершения: 

./runsomething             
May  5 09:46:35.000 INF runsomething started 
May  5 09:46:37.000 INF Summarizing results and exiting
May  5 09:46:37.000 INF Run results COMPLETED
May  5 09:46:39.000INF runsomething: DONE

Вот результаты с прерыванием: 

May  5 09:39:48.000 INF runsomething started
^CMay  5 09:39:50.000 INF runsomething: SIGTERM caught
May  5 09:39:50.000 INF Stopping all goroutines
May  5 09:39:50.000 INF GracefulShutdown: Started

Там несколько отсутствующих строк вывода. Учитывая приведенный выше фрагмент кода, я ожидал увидеть: 

...continued from above...
May  5 09:39:50.000 INF THIS SHOULD PRINT, WHY DOESNT IT? The sleep below also isn't run?
May  5 09:39:50.000 INF GracefulShutdown: Completed
May  5 09:39:50.000 INF runsomething: DONE

Вызовы time.Sleep(), похоже, не работают. После начального журнала, в котором указано GracefulShutdown: Started, нет паузы перед тихим завершением программы. Я попытался воспроизвести проблему на гораздо меньшем примере, который имитирует приведенный выше код, но он работает, как ожидалось. Я был бы признателен за любые идеи или дополнительные шаги по устранению неполадок, которые я мог бы попробовать.

EDIT: последний выполняемый оператор - это оператор журнала отладки. Когда я закомментировал следующее за ним fmt.Printf, программа работает должным образом. Примечание: он печатает то же []byte, что и оператор журнала над ним. 

    rsjson, err := json.Marshal(runSummary)
    if err != nil {
        log.Error().Err(err).Msgf("error marshaling RunSummary into string: %+v.\n")
        return
    }

    // TODO: debug stuff, only the printf should remain
    log.Info().Msgf("Run results: \n\n%s\n", rsjson)
    // TODO Removed Printf to see if it makes a difference
    // fmt.Printf("%s\n", string(rsjson))
    log.Info().Msgf("Run results COMPLETED")

1 Ответ

0 голосов
/ 05 мая 2020

Я понимаю, что сделал не так. Оказывается, код работает. Команда, которую я использовал, была не совсем той, которую я поставил в исходном вопросе. Если я запустил команду, как указано выше: 

./runsomething

, она будет работать должным образом при прерывании (^C).

Но фактическая команда выводит вывод следующим образом: 

./runsomething | jq .

Это демонстрирует поведение, описанное выше, вывод не печатается. Что меня обмануло, так это то, что логирование шло на stderr, так что казалось, что все работает, ЗА ИСКЛЮЧЕНИЕМ последнего fmt.Printf. Подумав об этом еще немного, я отменяю весь конвейер, то есть runsomething и jq, а не только runsomething. Дох!

...