91750


## 環境

Lubuntu 20.04 64bit  
node.js 16.17.1  
python 3.8.10

## 再現手順

(1) node.jsを使用し、適当なディレクトリでhttp-serverパッケージのHTTPサーバーをポート8000で起動する

[code]

    npx http-server --port 8000
    
[/code]

(2) pythonスクリプトをclient.pyという名前で用意する

[code]

    import asyncio
    
    async def client():
        reader, writer = await asyncio.open_connection('127.0.0.1', 8000)
        writer.write(f'GET / HTTP/1.1\r\nHost: 127.0.0.1\r\nConnection: keep-alive\r\n\r\n'.encode())
        await writer.drain()
        data = await reader.read(10240)
        writer.close()
        await writer.wait_closed()
    
    async def clients(N):
        await asyncio.gather(*[client() for _ in range(N)])
    
    asyncio.run(clients(0x10000))
    
[/code]

(3) (2)で用意したスクリプトを以下のように実行する

[code]

    python3 client.py;ss -an | grep 8000 | grep TIME-WAIT | wc -l
    
[/code]

※ **追記** : ulimit -n 1048576で実行しています

(4) 数分後以下のエラーが(2)の実行端末で表示される

[code]

    Traceback (most recent call last):
      File "client.py", line 14, in <module>
        asyncio.run(clients(0x10000))
      File "/usr/lib/python3.8/asyncio/runners.py", line 44, in run
        return loop.run_until_complete(main)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "client.py", line 12, in clients
        await asyncio.gather(*[client() for _ in range(N)])
      File "client.py", line 4, in client
        reader, writer = await asyncio.open_connection('127.0.0.1', 8000)
      File "/usr/lib/python3.8/asyncio/streams.py", line 52, in open_connection
        transport, _ = await loop.create_connection(
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1025, in create_connection
        raise exceptions[0]
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1010, in create_connection
        sock = await self._connect_sock(
      File "/usr/lib/python3.8/asyncio/base_events.py", line 924, in _connect_sock
        await self.sock_connect(sock, address)
      File "/usr/lib/python3.8/asyncio/selector_events.py", line 496, in sock_connect
        return await fut
      File "/usr/lib/python3.8/asyncio/selector_events.py", line 501, in _sock_connect
        sock.connect(address)
    OSError: [Errno 99] Cannot assign requested address
    16383
    
[/code]

## 質問

これは何が起きているエラーなのでしょうか？

## 追記

ちょっと書き換えました。

[code]

    import asyncio
    
    async def client(id):
        print(f'{id}: started')
        reader, writer = await asyncio.open_connection('127.0.0.1', 8000)
        writer.write(f'GET / HTTP/1.1\r\nHost: 127.0.0.1\r\nConnection: keep-alive\r\n\r\n'.encode())
        await writer.drain()
        # print(f'{id}: before read')
        data = await reader.read(10240)
        # print(data)
        # print(f'{id}: after read')
        writer.close()
        await writer.wait_closed()
        print(f'{id}: finished')
    
    async def clients(N):
        await asyncio.gather(*[client(i) for i in range(N)])
    
    asyncio.run(clients(0x10000))
    
[/code]


CC BY-SA 4.0
2022-10-22T05:12:46.240
91735
2022-10-29T02:32:50.180
2022-10-22T07:26:58.863
54957
54957
question
python linux network
ローカルホストでたくさん接続を開始するとエラーになる


`asyncio.open_connection('127.0.0.1', 8000)`
は接続相手のポート番号は指定されていますが、自分自身が使用するポート番号は指定されていません。このような場合、TCP/IPでは[ダイナミックポートもしくはエフェメラルポート](https://ja.wikipedia.org/wiki/%E3%83%9D%E3%83%BC%E3%83%88_\(%E3%82%B3%E3%83%B3%E3%83%94%E3%83%A5%E3%83%BC%E3%82%BF%E3%83%8D%E3%83%83%E3%83%88%E3%83%AF%E3%83%BC%E3%82%AF\)#%E3%83%9D%E3%83%BC%E3%83%88%E7%95%AA%E5%8F%B7%E3%81%AE%E7%A8%AE%E9%A1%9E)と呼ばれるポート番号を使用します。

[code]

    $ sysctl net.ipv4.ip_local_port_range
    net.ipv4.ip_local_port_range = 32768    60999
    
[/code]

手元のマシンでは上記範囲が設定されており、およそ28,000ポートしか用意されていません。

それとは別に、TCP/IPは相手との通信であり、自分が使用を終了したとしても相手が追加データを送ってくる可能性があります。その状態で別のプログラムにポートを割り当ててしまうと後でのプログラムは不正なデータを受信してしまうことになります。そういったトラブルを避けるためのクールダウンタイムとして
`TIME_WAIT` 状態で一定時間は再利用できなくなっています。

[code]

    $ sysctl net.ipv4.tcp_fin_timeout
    net.ipv4.tcp_fin_timeout = 60
    
[/code]

手元のマシンでは60秒は再利用しないことになっていました。

この２つのことがあり、 `asyncio.run(clients(0x10000))`
のように65,536回接続しようとしても使用可能なポートが得られず処理を開始できないことがあります。


CC BY-SA 4.0
2022-10-22T13:04:50.777
91743
2022-10-22T13:04:50.777
4236
91735
answer


## 調査

コードを以下のように改修し、状況が分かるようにしました。

[code]

    import asyncio
    import logging
    import traceback
    
    logger = logging.getLogger('test')
    logger.setLevel(logging.DEBUG)
    
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    for ch in [logging.StreamHandler(), logging.FileHandler('client.log')]:
        ch.setLevel(logging.DEBUG)
        ch.setFormatter(formatter)
        logger.addHandler(ch)
    
    async def client(id):
        try:
            logger.debug(f'{id}: started')
            reader, writer = await asyncio.open_connection('127.0.0.1', 8000)
            logger.debug(f'{id}: connection established')
            writer.write(f'GET / HTTP/1.1\r\nHost: 127.0.0.1\r\nConnection: keep-alive\r\n\r\n'.encode())
            await writer.drain()
            # logger.debug(f'{id}: before read')
            data = await reader.read(10240)
            # logger.debug(data)
            # logger.debug(f'{id}: after read')
            writer.close()
            await writer.wait_closed()
            logger.debug(f'{id}: finished')
        except BaseException as err:
            logger.error(f'{id}: ' + traceback.format_exc())
    
    async def clients(N):
        await asyncio.gather(*[client(i) for i in range(N)])
    
    asyncio.run(clients(0x10000))
    
[/code]

## 結果

[code]

    YYYY-MM-DD hh:mm:ss,sss - test - DEBUG - 0: started
    ...
    YYYY-MM-DD hh:mm:ss,sss - test - DEBUG - 28231: started
    YYYY-MM-DD hh:mm:ss,sss - test - DEBUG - 28232: started
    YYYY-MM-DD hh:mm:ss,sss - test - ERROR - 28232: Traceback (most recent call last):
    ...
      File "/usr/lib/python3.8/asyncio/selector_events.py", line 501, in _sock_connect
        sock.connect(address)
    OSError: [Errno 99] Cannot assign requested address
    ...
    (同様の出力が28233～65535まで)
    YYYY-MM-DD hh:mm:ss,sss - test - DEBUG - 0: connection established
    ...
    YYYY-MM-DD hh:mm:ss,sss - test - DEBUG - 28231: connection established
    YYYY-MM-DD hh:mm:ss,sss - test - DEBUG - 0: finished
    ...
    YYYY-MM-DD hh:mm:ss,sss - test - DEBUG - 28231: finished
    
[/code]

動的ポートのシステム割当数と正常終了した数を比較すると...

[code]

    $ sysctl net.ipv4.ip_local_port_range
    net.ipv4.ip_local_port_range = 32768    60999
    $ expr 60999 - 32768 + 1
    28232
    $ grep finished client.log | wc -l
    28232
    $
    
[/code]

## 結論

ポートの枯渇が原因で、connect(2)に失敗しているエラーだということが分かりました。  
※TIME-WAITの数が16383になっている理由は分かりません。

## 追記

以下に記述したようにTIME-WAITの個数に上限値があるからのようです。  
[TIME_WAITなポートが1分経たずに使われる](https://ja.stackoverflow.com/questions/91881/time-
wait%e3%81%aa%e3%83%9d%e3%83%bc%e3%83%88%e3%81%8c1%e5%88%86%e7%b5%8c%e3%81%9f%e3%81%9a%e3%81%ab%e4%bd%bf%e3%82%8f%e3%82%8c%e3%82%8b/91883#91883)


CC BY-SA 4.0
2022-10-23T01:02:01.257
91750
2022-10-29T02:32:50.180
2022-10-29T02:32:50.180
54957
54957
91735
answer