Socket通信後、SqlServerCe.SqlCeConnectionクラスを使用しているメソッドの呼び出しが遅くなる現象について

Question

Socket通信とSqlServerCeを使用したアプリケーションを作成しています。

以下の手順で現象が発生しています。

①Socketクラスを使用した単純な送受信を行う(TCPとUDPの両方で現象が発生することを確認しています。)

②アプリケーションを再起動して、SqlServerCe.SqlCeConnectionクラスを使用しているメソッドを呼び出そうとする

下記のようなコードだと、"Start testB"が表示されてから"Started testB"が表示されるまでに10秒程度かかる
    Private Sub Form1_Load(ByVal sender As Object, ByVal e As System.EventArgs) Handles Me.Load

        MsgBox("Start testB")

        _testB()

    End Sub

    Private Sub _testB()

        MsgBox("Started testB")

        _testA()

    End Sub

    Private Sub _testA()

        'インスタンスの生成だけでも10秒程度かかる(アプリケーション起動後の最初の1回だけ)

        'Dim sce As New System.Data.SqlServerCe.SqlCeEngine

        Dim scc As New System.Data.SqlServerCe.SqlCeConnection

    End Sub

※①と②を1つのアプリケーション上で実装して実行した場合、①と②を別々のアプリケーション上で実装して実行した場合の両方で現象が起きます。

上記は①と②を1つのアプリケーション上で実装して実行した場合を想定して記述しています。

①を第三者製のフリーツールで行って現象が起こることを確認しています。

[関連する現象]

・②を行うときに、LANケーブルを抜いたり、ローカルエリア接続を無効にしたりしていると、現象が発生しません。

なお、パソコン3台で確認を行ったところ、Visual Studioがインストールされている2台のパソコンでは現象が発生しませんでした。(まれに一瞬だけ止まることがある)

開発環境がインストールされていないパソコンでは常時発生しています。

原因や解決方法に心当たりがありましたら、教えてください。

よろしくお願い致します。

Answer 1

直接的な回答ではないですが

1. 細かい数字に意味はないですが、時間を測るならStopWatchクラスが使えると思います。
　 http://code.msdn.microsoft.com/windowsdesktop/C-Stopwatch-14e2440d
  Dim scc As New System.Data.SqlServerCe.SqlCeConnection
  の前後でStart,Stopして実際時間がかかっているのか測ったほうが良いと思います。
  提示されているコードだと最小限のコードとしては無駄が多いように（問題点が別のところにあるかもしれない）と思います。

2. System.Data.SqlServerCe.SqlCeConnectionは使ったことないですがSystem.Data.SqlClient.SqlConnectionと同じ用なものだとすると
  インスタンス作るときに接続文字列を渡していると思うのですが、それはどのような形でしょうか。
  > ②を行うときに、LANケーブルを抜いたり、ローカルエリア接続を無効にしたりしていると、現象が発生しません。
  ということなので、開発マシンとそれ以外でネットワークに関する設定がちょっと違う部分があったりしないでしょうか。

Answer 2

返信ありがとうございます。

> 1. 細かい数字に意味はないですが、時間を測るならStopWatchクラスが使えると思います。

→StopWatchクラスでの計測を行いました。

MsgBox("Start testB")のところでＳｔａｒｔして、MsgBox("Started testB")のところで計測結果(ミリ秒)を表示したところ10030前後となりました。

> Dim scc As New System.Data.SqlServerCe.SqlCeConnection
>  の前後でStart,Stopして実際時間がかかっているのか測ったほうが良いと思います。

→当初、私のほうでもここで時間がかかっていると考えたのですが、ここの前後ではほぼ0ミリ秒でした。

>インスタンス作るときに接続文字列を渡していると思うのですが、それはどのような形でしょうか。

→接続文字の有無に関わらず現象が発生します。指定しているものは以下のようなものです。

"Data Source = 'D:\test.sdf'; Password = 1234;"

>開発マシンとそれ以外でネットワークに関する設定がちょっと違う部分があったりしないでしょうか。

→確認してみましたが、ローカルエリア接続の設定は同じでした。ただ、ネットワークのデバイスは異なります。

正常：Broadcom NetXtreme 57xx Gigabit Controller

異常：Intel 825xx Gigabit Platform LAN Network Device

異常側で、デバイスのプロパティの設定を上から順にすべて変更して動作を確認しましたが、解消しませんでした。

記述し忘れていましたが、OSはすべてWindows 7 SP1 32bitです。

開発側はWindows 7のみインストール後、Windows UpdateでSP1へ更新、異常側はWindows 7 SP1適用済みのディスクからインストールしています。

Answer 3

「のところで」というあいまいな表現をせず、行の前か後ろかはっきりさせてください。また New System.Data.SqlServerCe.SqlCeConnection には時間を要していなかったとのことですから、どの行が１０秒要しているのか明示してください。

Answer 4

> Dim scc As New System.Data.SqlServerCe.SqlCeConnection
>  の前後でStart,Stopして実際時間がかかっているのか測ったほうが良いと思います。
> →当初、私のほうでもここで時間がかかっていると考えたのですが、ここの前後ではほぼ0ミリ秒でした。

本当にこれだけしか書いてない行だとすると、インスタンスを作っているのではなくて宣言しているだけなので時間はほとんどかからないと思います。
お聞きしたかったのは接続文字列を渡してインスタンスを作っている行でかかっている時間が長いのかどうかです。
インスタンスを作っている行で問題なければ、接続した後で何か操作していると思いますので、そちらの方の調査も必要かと思います。

Answer 5

> どの行が１０秒要しているのか明示してください。

→どの行が、と言えないので困っています。

文字通り、MsgBox("Started testB")をMsgBox(sw.ElapsedMilliseconds.ToString)としているだけです。

メソッドの呼び出しから、実際にメソッドが実行されるまでに時間がかかっています。

Answer 6

> 本当にこれだけしか書いてない行だとすると、インスタンスを作っているのではなくて宣言しているだけなので時間はほとんどかからないと思います。

→実際にこれだけです。問題が生じたプログラムから、原因箇所を絞っていった結果これだけになり、同様の問題が再現されています。

Answer 7

> どの行が１０秒要しているのか明示してください。

→どの行が、と言えないので困っています。

あり得ないです。10030ミリ秒という測定はどの行からどの行までの所要時間なのですか？ どの行の後にstartを入れて、どの行の前にstopを入れたのですか？ そこの間の行が１０秒要しているという意味になります。

それともstart()の直後にstop()を入れたら１０秒要したとでもいうのでしょうか？

Answer 8

> それともstart()の直後にstop()を入れたら１０秒要したとでもいうのでしょうか？

→プログラム上はメソッドを挟んでいるだけで、その通りです。ありえないとは私も思っていて、原因がわからず質問しています。

以下のプログラムは実際に動かして問題が生じているものとまったく同一のものです。

   Private sw As New Diagnostics.Stopwatch

    Private Sub Form1_Load(ByVal sender As Object, ByVal e As System.EventArgs) Handles Me.Load

        sw.Start()

        _testB()

    End Sub

    Private Sub _testB()

        MsgBox(sw.ElapsedMilliseconds.ToString) '←ここで10000前後の値が表示される

        _testA()

    End Sub

    Private Sub _testA()

        'インスタンスの生成だけでも10秒程度かかる(アプリケーション起動後の最初の1回だけ)　←このコメントが混乱を招いていますね。。。ないものと思ってください。

        'Dim sce As New System.Data.SqlServerCe.SqlCeEngine

        Dim scc As New System.Data.SqlServerCe.SqlCeConnection

    End Sub

Answer 9

あとで提示されているStopWatchを使っているソースだと、
sw.Start()してから_testB()を呼んで、_testA()する前にsw.Stopせずに経過時間を出していると見えます。
要するにメッセージボックスの表示にかかっている時間を表示しているだけに見えます（それでも10000って…）。
もっと単純に、新規のプロジェクト作って

    Private Sub Form1_Load(ByVal sender As System.Object, ByVal e As System.EventArgs) Handles MyBase.Load
        sw.Start()
        Dim conn As SqlCeConnection = New SqlCeConnection("Data Source = 'test.sdf'; Password = testpassword;")
        sw.Stop()
        MessageBox.Show(sw.ElapsedMilliseconds.ToString)
        sw.Reset()
    End Sub

だけにした場合かかっている時間はどんなもんでしょうか。
こちらでは16とかそんなもんの数字になります（sdfファイルを置いている場所がアプリと同じディレクトリだったりします）が、
その数値が10000とかになるんでしょうか。
それともこれだけだと早いけど、ソケット使う部分と組み合わせると遅くなるんでしょうか。それなら問題はここじゃなくて
ソケット使う部分になると思います。

Answer 10

> もっと単純に、新規のプロジェクト作って

→頂いたコードですと、フォームが開くまでに10秒程度かかります。

MessageBox.Show(sw.ElapsedMilliseconds.ToString)

で得られた結果は20～30程度でした。

> それともこれだけだと早いけど、ソケット使う部分と組み合わせると遅くなるんでしょうか。

→そうです。ソケット通信を行った後でなければ時間はかかりません。ソケット通信を行うプロジェクトとSqlServerCeを使うプロジェクトとを分けても現象が起きます。

ソケット通信プログラムは以下のように単純なもので、現象が生じることを確認しています。

Imports System.Net.Sockets

Public Class Form1

    Private _socket As System.Net.Sockets.Socket

    Private Sub Form1_FormClosing(ByVal sender As Object, ByVal e As System.Windows.Forms.FormClosingEventArgs) Handles Me.FormClosing
        _socket.Close()
        _socket = Nothing
    End Sub

    Private Sub btnOpen_Click(ByVal sender As System.Object, ByVal e As System.EventArgs) Handles btnOpen.Click
        'テキストボックスで送信先･送信元のIPアドレスとポート番号を入力
        If Not _open(Net.IPAddress.Parse(txtMyIP.Text), CInt(txtMyPort.Text), _
                     Net.IPAddress.Parse(txtToIP.Text), CInt(txtToPort.Text)) Then
            MsgBox("OpenNG")
        End If
    End Sub

    Private Sub btnSend_Click(ByVal sender As System.Object, ByVal e As System.EventArgs) Handles btnSend.Click
        'テキストボックスで送信データを入力
        If _send(txtSendData.Text) Then
        Else
            MsgBox("SendNG")
        End If
    End Sub

    Private Sub btnClear_Click(ByVal sender As System.Object, ByVal e As System.EventArgs) Handles btnClear.Click
        lblRecData.Text = ""
    End Sub

    Private Sub chkReceive_CheckedChanged(ByVal sender As System.Object, ByVal e As System.EventArgs) Handles chkReceive.CheckedChanged
        '受信タイマを動かすかどうかのチェックボックス
        If chkReceive.Checked Then
            tmrReceive.Start()
        Else
            tmrReceive.Stop()
        End If
    End Sub

    Private Sub tmrReceive_Tick(ByVal sender As System.Object, ByVal e As System.EventArgs) Handles tmrReceive.Tick
        Dim rd As String = ""
        If _receive(rd) Then
            '受信データをラベルに表示
            lblRecData.Text = rd
        End If
    End Sub

    ''' <summary>
    ''' オープン処理
    ''' </summary>
    Private Function _open(ByVal myIP As Net.IPAddress, ByVal myPort As Integer, _
                           ByVal toIP As Net.IPAddress, ByVal toPort As Integer) As Boolean

        Dim result As Boolean = True

        Try
            'UDP
            _socket = New Socket(AddressFamily.InterNetwork, SocketType.Dgram, ProtocolType.Udp)
            '送信元
            _socket.Bind(New Net.IPEndPoint(myIP, myPort))
            '送信先
            _socket.Connect(New Net.IPEndPoint(toIP, toPort))
        Catch ex As Exception
            result = False
        End Try

        Return result

    End Function

    ''' <summary>
    ''' 送信処理
    ''' </summary>
    Private Function _send(ByVal sendData As String) As Boolean

        Dim result As Boolean = True

        Try
            Dim sendBytes As Byte() = System.Text.Encoding.UTF8.GetBytes(sendData)
            _socket.Send(sendBytes) '送信
        Catch ex As Exception
            result = False
        End Try

        Return result

    End Function

    ''' <summary>
    ''' 受信処理
    ''' </summary>
    Private Function _receive(ByRef receiveData As String) As Boolean

        Dim result As Boolean = True
        receiveData = ""

        Try
            If _socket.Available > 0 Then
                Dim receiveBytes(_socket.Available - 1) As Byte
                _socket.Receive(receiveBytes)   '受信
                receiveData = System.Text.Encoding.UTF8.GetString(receiveBytes, 0, receiveBytes.Length)
            Else
                result = False
            End If

        Catch ex As Exception
            result = False
        End Try

        Return result

    End Function

End Class

Answer 11

> →頂いたコードですと、フォームが開くまでに10秒程度かかります。

> →そうです。ソケット通信を行った後でなければ時間はかかりません。

これはどっちなのでしょうか。
私が提示したのは純粋にフォームを開くだけ、ということを意図しましたが、
普通に考えて、何も処理していないなら時間がかかることもないわけで、
もしインタンスを作っている部分で時間がかかっていないなら
フォームを開くだけで10秒かかっているということになると思いますが、
それは普通には考えにくいなあ、と思います。
なのでフォーム開くまでに何かしていませんか？
それが提示してもらったコードからは私には読み取れません。

＃ なんか考え違いしてるかなあ

Answer 12

　確認ですが、Socket 通信を行う前だと、どれくらいの数値でしょうか。また、「SqlServerCe.SqlCeConnectionクラスを使用しているメソッドの呼び出しが遅くなる」ということですが、ほかのメソッドは、どれくらいの数値でしょうか。さらに、2回目、3回目の呼び出しも、やはり遅いのでしょうか。
例：
再起動直後　　　3ミリ秒
ソケット通信後　10030ミリ秒
↑
文章では確かに書いてあるのですが、このように並べて書いた方が誤解が少なくて済みます。また、「再起動」と書いたことで、「じゃぁ、再ログオンは？」という、別の切り口が見つけられます。おそらく、タイトルに端的に書かれているので本文では省略されたのだと思いますが、読む方にとっては、タイトルが内容を示していない投稿が多くあるので、関連づけていないかもしれません。はい、私のことです。ごめんなさい。

　あと、ネットワーク アダプターのメーカーは、どこですか？ [ipconfig /all] で、「説明」のところに出てくるものをそのままお願いします。「パソコン3台で確認を行ったところ、Visual Studioがインストールされている2台のパソコンでは現象が発生しませんでした」ということですが、3台とも同じメーカーでしょうか？おっと、Broadcom と Intel だと書いてあった。「パソコン3台」と書いてありましたが、2台分のメーカーしか書かれていません。VS のインストール状況とあわせて、追記願います。
例：
PC1 発生する　 VS なし Intel 825xx Gigabit Platform LAN Network Device
PC2 発生しない VS あり Broadcom NetXtreme 57xx Gigabit Controller
PC3 発生しない VS あり Broadcom NetXtreme 57xx Gigabit Controller
↑
このように整理して、現象の発生と、Visual Studio のインストール状況、ネットワーク アダプターの関連があるのかないのか、調べます。次は、「VS をアンインストールしたら？」「PC1 に VS をインストールしたら？」と続き、原因の絞り込みに役立ちます。

　あ、「示されている例の通りです」は、なしでお願いします。こういう場所での質問は「プレゼンテーション」ですので、「回答者を魅了する方法」を考えて、工夫して書いてください。

　「開発環境がインストールされていないパソコンでは常時発生しています。」ということですが、どのようにして、開発したものを配置しましたか？EXE ファイルをコピーしただけ、であれば、VS のインストール プロジェクトの機能で依存関係を調べ、依存しているファイルをインストール、あるいは更新することで解決するかもしれません。

　「インスタンスの生成だけでも10秒程度かかる」と書かれていますが、インスタンスを生成せず、単に宣言しただけの場合は、どうでしょうか。
　ん～？遅くなるのは、「使用しているメソッドの呼び出し」ですっけ？「使用しているメソッドを呼び出すメソッドの呼び出し」ですよね？つまり、最初の投稿のコードだと、_testA が「使用しているメソッド」で、_testA の呼び出しが遅いのではなく、_testA を呼び出している _testB の呼び出しが、遅くなっているのですよね？これも、呼び出し毎に何秒と書かれていれば、誤解が少なくなりますよね。
例：
　　　　　　　　　再起動直後　　ソケット通信後
_testA 呼び出し　　　3ミリ秒　　　10030ミリ秒
_testB 呼び出し　　　3ミリ秒　　　　　3ミリ秒

　それと、Windows 7 でネットワークがらみであるなら、「［Windows 7編］ネットワーク設定を標準で使ってはいけない」を参考に、SNP をオフした場合にどうか、試してみてください。まず関係ないと思いますが、これが絡んでいるなら、どんな不具合が発生するかわからないので。

---

Jitta＠わんくま同盟

Answer 13

mars12様、Jitta様、返信ありがとうございます。

調査を進めたところ、該当PCのネットワーク設定が原因とわかりました。

ネットワーク設定で、デフォルトゲートウェイ[192.168.1.1]、DNSサーバー[192.168.2.10]を設定しているのですが、現在テスト環境のため、実際にはデフォルトゲートウェイ、DNSサーバーがありません。

ネットワークアナライザを使用して、パケットを見たところ、止まっている間に以下のような通信が行われていました。（自IP=192.168.1.240）

Time      Source                     Destination           Protocol                                  Info

0.00     f0:1f:...                      Broadcast               ARP            Who has 192.168.1.1?    Tell 192.168.1.240

0.98     f0:1f:...                      Broadcast               ARP            Who has 192.168.1.1?    Tell 192.168.1.240

1.97     f0:1f:...                      Broadcast               ARP            Who has 192.168.1.1?    Tell 192.168.1.240

3.19     192.168.1.240          224.0.0.252          LLMNR          Standard query A wpad

3.29     192.168.1.240          224.0.0.252          LLMNR          Standard query A wpad

3.50     192.168.1.240          192.168.11.255     NBNS           Name query NG WPAD<00>

4.25     192.168.1.240          192.168.11.255     NBNS           Name query NG WPAD<00>

4.61     192.168.1.240          192.168.11.255     NBNS           Name query NG WPAD<00>

5.79     f0:1f:...                      Broadcast               ARP            Who has 192.168.1.1?    Tell 192.168.1.240

6.50     f0:1f:...                      Broadcast               ARP            Who has 192.168.1.1?    Tell 192.168.1.240

7.50     f0:1f:...                      Broadcast               ARP            Who has 192.168.1.1?    Tell 192.168.1.240

8.97     192.168.1.240          224.0.0.252          LLMNR          Standard query A wpad

9.08     192.168.1.240          224.0.0.252          LLMNR          Standard query A wpad

9.28     192.168.1.240          192.168.11.255    NBNS            Name query NG WPAD<00>

10.04   192.168.1.240          192.168.11.255    NBNS            Name query NG WPAD<00>

10.80   192.168.1.240          192.168.11.255    NBNS            Name query NG WPAD<00>

おそらく、名前解決のタイムアウトを待っているため止まっていると考えられます。

そこで、デフォルトゲートウェイの設定をなしにしたところARPの行がなくなり、DNSサーバーの設定をなしにしたところLLMNRの行がなくなり、NetBiosの設定を無効にしたところNBNSの行がなくなり、結果止まらなくなりました。

ただ、同様に設定した開発環境のPCでは、上記のパケットが見られず、止まりませんでした。

なぜ、SqlServerCeを使おうとすると上記パケットのやりとりが行われるかはわかりませんが、原因?がわかったので、ここで切りにしたいと思います。

（テスト環境でなければ、止まっても短時間だと思われるため。。。）

> 「［Windows 7編］ネットワーク設定を標準で使ってはいけない」を参考に

SNPを無効にしてみましたが、変化ありませんでした。

わかりづらい文章に長々とお付き合いただき、ありがとうございました。

また質問することがあれば、魅せる文章で書けるよう努力したいと思います。