質問をすることでしか得られない、回答やアドバイスがある。

15分調べてもわからないことは、質問しよう!

ただいまの
回答率

87.49%

ローカルホストが突然全く反応しなくなります

解決済

回答 1

投稿 編集

  • 評価
  • クリップ 1
  • VIEW 666

score 5

現象

GoでLocalhostを立て、そこにブラウザでアクセスする形式(同一マシン内)のアプリケーションを作成しているのですが、
ときどきローカルホストから全くレスポンスが返ってこなくなるという事象が生じており、非常に困っています。

たとえば以下のようになります。

  1. しばらく正常に動作している
  2. リクエスト1をおこなう →すると突然レスポンスが返ってこない
  3. このあと、リクエスト2、リクエスト3と続けてリクエストを出しても、全て無反応となる。

上記のように、ときどきローカルホストが全く無反応の状態になります。

ローカルホストが動作しているWindowsのdos窓を見ると、リクエスト1の時点でログの流れがストップしています。
しかしここでdos窓をクリックしてf5キーを押すと、突然ログが流れ始めます。そして、リクエスト1,2,3に対するレスポンスが一度に返ってきます。

環境などは以下です。

Win10 64bit
Go1.13
github.com/gorilla/mux を利用

r := mux.NewRouter()
r.HandleFunc("/path", Func).Methods("GET", "POST", "OPTIONS")  ...

srv := http.Server{
    Addr:              ":48000",
    Handler:           r,
    TLSConfig:         nil,
    ReadTimeout:       0,
    ReadHeaderTimeout: 0,
    WriteTimeout:      0,
    IdleTimeout:       0,
    MaxHeaderBytes:    0,
    TLSNextProto:      nil,
    ConnState:         nil,
    ErrorLog:          nil,
    BaseContext:       nil,
    ConnContext:       nil,
}
srv.SetKeepAlivesEnabled(false)  //keepaliveが悪影響を及ぼす場合があると聞いてオフにしてみた
err := srv.ListenAndServe()
if err != nil {
    log.Fatalf(err.Error())
}

条件、再現性など

上記停止現象の発生条件は分かりません。

メソッドはget のときも postのときもあります。
またlocalhost内でエラー(ロジックに由来するエラー)が起きているときもありますが、全く問題が無い(リクエストは所定の形式でなされており、ローカルホストでの処理中のエラーも起きていない)場合もあります。

リクエストはブラウザ(fetchを使用)から送る場合でも、ツール(postmanを使用)で送る場合でも発生します。
発生頻度はそれなりに高く、リクエスト数十回に1回くらい見かける印象です(プロダクトでこの頻度だと使い物にならないと思います)。

以上のような状況であるため、この場合にこうなるというのは見つかられていません。あるとき突然なるという認識です。
ただしその状態が生じた場合、「dos窓をクリックしてf5キー」によって確実に回復します。これは今のところ例外無しです。

試したこと

正直なにが起きているのかよく理解できていません。
F5キーで回復するというところに何か現象を理解するヒントがあるようには思えるのですが。
keepaliveが悪影響を及ぼす場合があるという情報を見かけたので、srv.SetKeepAlivesEnabled(false)としてみましたが改善しませんでした。

質問

以上のような状況ですが、どのように対処したらよいでしょうか。
アプリケーションの動作の根幹にかかわる部分で、かなり深刻なのですが、解決方法が分からず非常に困っています。
アドバイスいただければ幸いです。
よろしくお願いいたします。

追記:サンプルコード

ご指摘を受け、実際のプログラムの挙動に似せたものをサンプルコードとして作成してみました。

これを作っている過程で気づいたのですが、このプログラムはグローバル変数としてキャッシュを持っています。
そのキャッシュデータに対する同時アクセス制御(mutex)に問題があるのではないかと思い、mutexまわりをいくつか修正してみたところ、停止現象がかなり減った感じがしています。
そのため現時点ではグローバル変数への同時アクセスが影響しているのではないかと疑っています。
(ただし、それがF5で解消するというのもよく分からない話のように思え、この点の疑問は残っています)

実際のプログラムに似せるため、プログラム内にファイルシステムへのアクセスが存在します。ご注意お願いします。

package main

import (
    "bufio"
    "encoding/json"
    "io/ioutil"
    "log"
    "net/http"
    "os"
    "path"
    "strconv"
    "sync"

    "github.com/gorilla/mux"
)

var (
    DataCache = map[string]string{}
    Datapath  string
    mutex     sync.RWMutex
)

type res_ping struct {
    Msg string `json:"msg"`
}

func GetPing(w http.ResponseWriter, r *http.Request) {
    log.Println("GetPingStart")
    defer log.Println("GetPingEnd")

    res := res_ping{Msg: "server_alive"}
    b, _ := json.Marshal(res)
    w.Write(b)
}

type res_get struct {
    Msg string `json:"msg"`
}

func GetData(w http.ResponseWriter, r *http.Request) {
    log.Println("GetDataStart")
    defer log.Println("GetDataEnd")

    line, _ := mux.Vars(r)["line"]

    if line == "" {
        line = "0"
    }
    mutex.RLock()
    msg := DataCache[line]
    mutex.RUnlock()

    res := res_get{Msg: msg}
    b, _ := json.Marshal(res)
    w.Write(b)

}

type req_post struct {
    Data string `json:"data"`
}

type res_post struct {
    Msg string `json:"msg"`
}

func PostData(w http.ResponseWriter, r *http.Request) {
    log.Println("PostDataStart")
    defer log.Println("PostDataEnd")

    body := r.Body
    defer body.Close()
    b, _ := ioutil.ReadAll(body)
    req := req_post{}
    _ = json.Unmarshal(b, &req)
    data := req.Data

    mutex.Lock()
    defer mutex.Unlock()
    file, _ := os.OpenFile(Datapath, os.O_WRONLY|os.O_APPEND, 0666)
    defer file.Close()
    file.WriteString(data + "\n")
    file.Close()
    readdata()

    res := res_post{Msg: "OK"}
    rb, _ := json.Marshal(res)
    w.Write(rb)

}

func SetJsonheader(w http.ResponseWriter) {
    w.Header().Set("Content-Type", "application/json")
}

func Wrap(f func(w http.ResponseWriter, r *http.Request)) func(w http.ResponseWriter, r *http.Request) {
    return func(w http.ResponseWriter, r *http.Request) {
        EnableCors(&w)
        SetJsonheader(w)
        f(w, r)
    }
}

func EnableCors(w *http.ResponseWriter) {
    (*w).Header().Set("Access-Control-Allow-Origin", "http://localhost:8004")
    (*w).Header().Set("Access-Control-Allow-Methods", "POST, GET, OPTIONS, PUT, DELETE")
    (*w).Header().Set("Access-Control-Allow-Headers", "Accept, Content-Type, Content-Length, Accept-Encoding, X-CSRF-Token, Authorization")
}

func setup() {
    log.Println(Datapath)
    file, err := os.Create(Datapath)
    if err != nil {
        log.Fatal(err)
    }
    defer file.Close()
    // 実際の挙動に近づけるためにファイル書き込み(データ多め)をおこなっています。問題があれば適宜修正してください。
    for i := 0; i < 10000; i++ {
        _, _ = file.WriteString("data898999898989898998989ddddd\n")
    }
    file.Close()

    readdata()
    //DataCache["0"] = "data0"
    //DataCache["1"] = "data1"
    //DataCache["2"] = "data2"
}

func readdata() {
    file, _ := os.Open(Datapath)
    defer file.Close()
    sc := bufio.NewScanner(file)
    count := 0
    for sc.Scan() {
        DataCache[strconv.Itoa(count)] = sc.Text()
        count++
    }
}

func main() {

    datadir := os.TempDir()
    datapath := path.Join(datadir, "data_6f3eb709jlgq0w2h.txt")
    Datapath = datapath
    setup()
    defer os.Remove(datapath)

    r := mux.NewRouter()
    r.HandleFunc("/ping", Wrap(GetPing)).Methods("GET", "POST", "OPTIONS")
    r.HandleFunc("/data/{line}", Wrap(GetData)).Methods("GET", "OPTIONS")
    r.HandleFunc("/data", Wrap(GetData)).Methods("GET", "OPTIONS")
    r.HandleFunc("/data", Wrap(PostData)).Methods("POST", "OPTIONS")

    srv := http.Server{
        Addr:              ":48000",
        Handler:           r,
        TLSConfig:         nil,
        ReadTimeout:       0,
        ReadHeaderTimeout: 0,
        WriteTimeout:      0,
        IdleTimeout:       0,
        MaxHeaderBytes:    0,
        TLSNextProto:      nil,
        ConnState:         nil,
        ErrorLog:          nil,
        BaseContext:       nil,
        ConnContext:       nil,
    }
    log.Println("start")
    srv.SetKeepAlivesEnabled(false)
    err := srv.ListenAndServe()
    if err != nil {
        log.Fatalf(err.Error())
    }
}
  • 気になる質問をクリップする

    クリップした質問は、後からいつでもマイページで確認できます。

    またクリップした質問に回答があった際、通知やメールを受け取ることができます。

    クリップを取り消します

  • 良い質問の評価を上げる

    以下のような質問は評価を上げましょう

    • 質問内容が明確
    • 自分も答えを知りたい
    • 質問者以外のユーザにも役立つ

    評価が高い質問は、TOPページの「注目」タブのフィードに表示されやすくなります。

    質問の評価を上げたことを取り消します

  • 評価を下げられる数の上限に達しました

    評価を下げることができません

    • 1日5回まで評価を下げられます
    • 1日に1ユーザに対して2回まで評価を下げられます

    質問の評価を下げる

    teratailでは下記のような質問を「具体的に困っていることがない質問」、「サイトポリシーに違反する質問」と定義し、推奨していません。

    • プログラミングに関係のない質問
    • やってほしいことだけを記載した丸投げの質問
    • 問題・課題が含まれていない質問
    • 意図的に内容が抹消された質問
    • 過去に投稿した質問と同じ内容の質問
    • 広告と受け取られるような投稿

    評価が下がると、TOPページの「アクティブ」「注目」タブのフィードに表示されにくくなります。

    質問の評価を下げたことを取り消します

    この機能は開放されていません

    評価を下げる条件を満たしてません

    評価を下げる理由を選択してください

    詳細な説明はこちら

    上記に当てはまらず、質問内容が明確になっていない質問には「情報の追加・修正依頼」機能からコメントをしてください。

    質問の評価を下げる機能の利用条件

    この機能を利用するためには、以下の事項を行う必要があります。

質問への追記・修正、ベストアンサー選択の依頼

  • nobonobo

    2020/02/01 08:04

    コネクション数の制御がおかしくなってる可能性は高いです。

    キャンセル

  • ryoyai

    2020/02/01 11:22

    ! Bodyの件、こちらですか。始めて知りました。ありがとうございます。

    type Request
    // Body is the request's body.
    //
    // For client requests, a nil body means the request has no
    // body, such as a GET request. The HTTP Client's Transport
    // is responsible for calling the Close method.
    //
    // For server requests, the Request Body is always non-nil
    // but will return EOF immediately when no body is present.
    // The Server will close the request body. The ServeHTTP
    // Handler does not need to.
    Body io.ReadCloser
    https://golang.org/pkg/net/http/#Request

    キャンセル

  • ryoyai

    2020/02/02 13:06

    数日間問題が起きていないので、一応解決したということにして、まとめを投稿しました。ご丁寧に対応いただきありがとうございました。

    キャンセル

回答 1

check解決した方法

0

数日間、停止現象は出ていません。完璧とは言えませんが、一応解決としたいと思います。
以下、知見を記します。

変数への同時読み書きに注意

GolangのLocalhostが特段のエラー表示も無く突然動作を停止する場合、変数に対する同時読み書き(以下、同時RW)が問題となっている可能性があります。
グローバル変数にキャッシュを持たせているような構成の場合には特に注意してください。

Goのサーバーは標準で並行処理を行います(goroutine)。サーバー内でグローバル変数を考え無しに利用すると、常に変数への同時RWのリスクが生じます。
手元の検証結果によれば、Mapへの同時RWはすぐにPanicを起こしますが、stringや構造体への同時RWはPanicを起こすとは限らないようです(検証範囲ではPanicが起きなかった)。そのため問題の発見が難しくなるかもしれません。

変数の同時RWを理解する上で、下記の記事が役に立ちました。注意則を抽出するならば、「複数のプロセスから、対策無しに同じ変数を扱うことは、常に危険である」と言えると思います。

Goでスレッド(goroutine)セーフなプログラムを書くために必ず注意しなければいけない点

Mutexの利用

変数の同時アクセスの制御には、sync.Mutexを利用します。(サンプルコード参照)
sync.Mutexはインスタンスごとにロックアンロックのスコープ?を持ちますので、変数A,B,Cについてそれぞれ別の制御をおこなうならば、3つのMutexをインスタンス化し、それをなんらかの方法で共有します(引数での受け渡しのほか、Mutex自体をグローバル変数として共有しても問題無いと理解しています)。

完全ではないものの、以上で一応の解決としたいと思います。

補足:サンプルコードの重要性

なお、途中でサンプルコードを作るようにという助言をいただきました。
掲載したサンプルコードを作るのに90分を要しましたが、作っている過程で上記の問題にすぐに気づくことができました。
また、その後、本番プロダクトでは難しい「実験」に利用することもできるようになって、利便性も感じています。
本質部分で本番コードと似たサンプルコードを作る、というのは、もちろん基本と言えると思いますが、あらためて有用性を理解しました。

投稿

  • 回答の評価を上げる

    以下のような回答は評価を上げましょう

    • 正しい回答
    • わかりやすい回答
    • ためになる回答

    評価が高い回答ほどページの上位に表示されます。

  • 回答の評価を下げる

    下記のような回答は推奨されていません。

    • 間違っている回答
    • 質問の回答になっていない投稿
    • スパムや攻撃的な表現を用いた投稿

    評価を下げる際はその理由を明確に伝え、適切な回答に修正してもらいましょう。

  • 2020/02/03 07:26 編集

    全ての型の値について同時読み書きが不定な挙動を招くことはありません。
    起こるとすれば正常に読み書きか、panicかの二択です。スライスは意図しないでデータセットになる可能性はありますが、勝手に処理が中断するようなことはありません。

    キャンセル

  • 2020/02/03 10:40

    停止したかのような挙動はデッドロックしたgoroutineが発生しているか、panicを捨てている処理があるはず(http.Serverはrecover処理で補足したpanicをErrorLogまたは標準ロガーで出力しようとします)

    キャンセル

15分調べてもわからないことは、teratailで質問しよう!

  • ただいまの回答率 87.49%
  • 質問をまとめることで、思考を整理して素早く解決
  • テンプレート機能で、簡単に質問をまとめられる

関連した質問

同じタグがついた質問を見る