netperf
netperf copied to clipboard
AhmedSoliman
Test aborted between NAS and pc (windows)
Server
NAS Synology Linux aarch64-unknown-linux-musl
[2021-04-05T14:58:25Z TRACE mio::poll] registering event source with poller: token=Token(1), interests=READABLE | WRITABLE
[2021-04-05T14:58:25Z INFO netperf::server] Accepted connection from [::ffff:192.168.1.28]:62535
[2021-04-05T14:58:25Z DEBUG netperf::common::net_utils] Received a control message (77 bytes) in 1 iterations
[2021-04-05T14:58:25Z DEBUG netperf::server] Hello received: 9c1c401d-ed25-4498-addb-fa51a0351d90
[2021-04-05T14:58:25Z DEBUG netperf::common::net_utils] Sent: 31 bytes
[2021-04-05T14:58:25Z DEBUG netperf::common::net_utils] Received a control message (200 bytes) in 1 iterations
[2021-04-05T14:58:25Z INFO netperf::server] [[::ffff:192.168.1.28]:62535] Test Created
[2021-04-05T14:58:25Z DEBUG netperf::controller] Controller has started
[2021-04-05T14:58:25Z DEBUG netperf::controller] Controller state: TestStart
[2021-04-05T14:58:25Z DEBUG netperf::controller] Test is initialising
[2021-04-05T14:58:25Z DEBUG netperf::common::net_utils] Sent: 102 bytes
[2021-04-05T14:58:25Z DEBUG netperf::controller] Controller state: CreateStreams { cookie: "9c1c401d-ed25-4498-addb-fa51a0351d90" }
[2021-04-05T14:58:25Z DEBUG netperf::controller] Waiting for data streams to be connected
[2021-04-05T14:58:25Z TRACE mio::poll] registering event source with poller: token=Token(2), interests=READABLE | WRITABLE
[2021-04-05T14:58:25Z DEBUG netperf::common::net_utils] Received a control message (77 bytes) in 1 iterations
[2021-04-05T14:58:25Z DEBUG netperf::common::net_utils] Sent: 31 bytes
[2021-04-05T14:58:25Z DEBUG netperf::common::net_utils] Sent: 44 bytes
[2021-04-05T14:58:25Z DEBUG netperf::controller] Controller state: Running
[2021-04-05T14:58:25Z DEBUG netperf::controller] Streams have been created, starting the load test
[ ID] Interval Transfer Bitrate
[2021-04-05T14:58:25Z DEBUG netperf::controller] Broadcasting to streams StartLoad
[2021-04-05T14:58:25Z DEBUG netperf::common::stream_worker] Data stream 0 created (receiving), waiting for the StartLoad signal!
[2021-04-05T14:58:25Z WARN netperf::common::stream_worker] Stream 0's connection has been closed.
[2021-04-05T14:58:25Z TRACE mio::poll] deregistering event source from poller
[2021-04-05T14:58:25Z DEBUG netperf::common::net_utils] Sent: 52 bytes
[2021-04-05T14:58:25Z DEBUG netperf::controller] Controller state: ExchangeResults
[2021-04-05T14:58:25Z DEBUG netperf::controller] Broadcasting to streams Terminate
[2021-04-05T14:58:25Z TRACE mio::poll] registering event source with poller: token=Token(16777218), interests=READABLE | WRITABLE
[2021-04-05T14:58:25Z INFO netperf::server] Test already in-flight, rejecting connection from [::ffff:192.168.1.28]:62537
[2021-04-05T14:58:25Z DEBUG netperf::common::net_utils] Sent: 55 bytes
[2021-04-05T14:58:25Z TRACE mio::poll] deregistering event source from poller
[2021-04-05T14:58:25Z TRACE mio::poll] deregistering event source from poller
[2021-04-05T14:58:25Z DEBUG netperf::server] Controller aborted: unexpected end of file
Test aborted!
Client
Windows target = x86_64-pc-windows-gnu
[2021-04-05T14:58:27Z INFO netperf] LogLevel: TRACE
[2021-04-05T14:58:27Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE | WRITABLE
Connecting to (192.168.1.23:7559) ...Connected!
[2021-04-05T14:58:27Z DEBUG netperf::common::net_utils] Sent: 81 bytes
[2021-04-05T14:58:27Z DEBUG netperf::client] Hello sent!
[2021-04-05T14:58:27Z DEBUG netperf::common::net_utils] Received a control message (27 bytes) in 1 iterations
[2021-04-05T14:58:27Z DEBUG netperf::client] Welcome received!
[2021-04-05T14:58:27Z DEBUG netperf::common::net_utils] Sent: 204 bytes
[2021-04-05T14:58:27Z DEBUG netperf::client] Params sent!
[2021-04-05T14:58:27Z DEBUG netperf::controller] Controller has started
[2021-04-05T14:58:27Z DEBUG netperf::controller] Controller state: TestStart
[2021-04-05T14:58:27Z DEBUG netperf::common::net_utils] Received a control message (98 bytes) in 1 iterations
[2021-04-05T14:58:27Z DEBUG netperf::controller] Controller state: CreateStreams { cookie: "9c1c401d-ed25-4498-addb-fa51a0351d90" }
[2021-04-05T14:58:27Z DEBUG netperf::controller] We should create data streams now
[2021-04-05T14:58:27Z DEBUG netperf::controller] Opening a data stream to (192.168.1.23:7559) ...
[2021-04-05T14:58:27Z TRACE mio::poll] registering event source with poller: token=Token(1), interests=READABLE | WRITABLE
[2021-04-05T14:58:27Z DEBUG netperf::common::net_utils] Sent: 81 bytes
[2021-04-05T14:58:27Z DEBUG netperf::common::net_utils] Received a control message (27 bytes) in 1 iterations
[2021-04-05T14:58:27Z DEBUG netperf::controller] Data stream created to 192.168.1.23:7559
[2021-04-05T14:58:27Z TRACE mio::poll] deregistering event source from poller
[2021-04-05T14:58:27Z WARN netperf::controller] Stream 0 has terminated with an error, we cannot fetch its total stream stats. This means that the results might be partial
[2021-04-05T14:58:27Z DEBUG netperf::controller] Controller state: CreateStreams { cookie: "9c1c401d-ed25-4498-addb-fa51a0351d90" }
[2021-04-05T14:58:27Z DEBUG netperf::controller] We should create data streams now
[2021-04-05T14:58:27Z DEBUG netperf::controller] Opening a data stream to (192.168.1.23:7559) ...
[2021-04-05T14:58:27Z TRACE mio::poll] registering event source with poller: token=Token(16777217), interests=READABLE | WRITABLE
[2021-04-05T14:58:27Z DEBUG netperf::common::net_utils] Sent: 81 bytes
[2021-04-05T14:58:27Z DEBUG netperf::common::net_utils] Received a control message (51 bytes) in 1 iterations
[2021-04-05T14:58:27Z TRACE mio::poll] deregistering event source from poller
[2021-04-05T14:58:27Z TRACE mio::poll] deregistering event source from poller
Error: Access denied: Test already in-flight
From the error message, it sounds like you have another in-flight test running on that server. If that's not the case, please try to restart the server and give it another go. Let me know how it went.
Also, a new build has been pushed, can you use that one? namely 0.2.2.
I am having a similar issue with netperf 0.2.2. Even though the test is the first test performed on server, the server and client cannot establish a link.
Server: Linux Mint 20.2 amd64 (glibc)
$ netperf -s -vvv
[2021-08-03T07:54:32Z INFO netperf] LogLevel: DEBUG
--------------------------------------
Listening on port 7559
--------------------------------------
[2021-08-03T07:54:36Z INFO netperf::server] Accepted connection from [::ffff:192.168.78.200]:4244
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Received a control message (77 bytes) in 1 iterations
[2021-08-03T07:54:36Z DEBUG netperf::server] Hello received: b959b4f5-d437-4606-94ca-e70c51071899
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 31 bytes
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Received a control message (200 bytes) in 1 iterations
[2021-08-03T07:54:36Z INFO netperf::server] [[::ffff:192.168.78.200]:4244] Test Created
[2021-08-03T07:54:36Z DEBUG netperf::controller] Controller has started
[2021-08-03T07:54:36Z DEBUG netperf::controller] Controller state: TestStart
[2021-08-03T07:54:36Z DEBUG netperf::controller] Test is initialising
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 102 bytes
[2021-08-03T07:54:36Z DEBUG netperf::controller] Controller state: CreateStreams { cookie: "b959b4f5-d437-4606-94ca-e70c51071899" }
[2021-08-03T07:54:36Z DEBUG netperf::controller] Waiting for data streams to be connected
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Received a control message (77 bytes) in 1 iterations
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 31 bytes
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 44 bytes
[2021-08-03T07:54:36Z DEBUG netperf::controller] Controller state: Running
[2021-08-03T07:54:36Z DEBUG netperf::controller] Streams have been created, starting the load test
[ ID] Interval Transfer Bitrate
[2021-08-03T07:54:36Z DEBUG netperf::controller] Broadcasting to streams StartLoad
[2021-08-03T07:54:36Z DEBUG netperf::common::stream_worker] Data stream 0 created (receiving), waiting for the StartLoad signal!
[2021-08-03T07:54:36Z WARN netperf::common::stream_worker] Stream 0's connection has been closed.
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 52 bytes
[2021-08-03T07:54:36Z DEBUG netperf::controller] Controller state: ExchangeResults
[2021-08-03T07:54:36Z DEBUG netperf::controller] Broadcasting to streams Terminate
[2021-08-03T07:54:36Z INFO netperf::server] Test already in-flight, rejecting connection from [::ffff:192.168.78.200]:4246
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 55 bytes
[2021-08-03T07:54:36Z DEBUG netperf::server] Controller aborted: unexpected end of file
Test aborted!
Client: Windows 10 x64
> netperf -c 192.168.78.210 -vvv
[2021-08-03T07:54:36Z INFO netperf] LogLevel: DEBUG
Connecting to (192.168.78.210:7559)... Connected!
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 81 bytes
[2021-08-03T07:54:36Z DEBUG netperf::client] Hello sent!
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Received a control message (27 bytes) in 1 iterations
[2021-08-03T07:54:36Z DEBUG netperf::client] Welcome received!
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 204 bytes
[2021-08-03T07:54:36Z DEBUG netperf::client] Params sent!
[2021-08-03T07:54:36Z DEBUG netperf::controller] Controller has started
[2021-08-03T07:54:36Z DEBUG netperf::controller] Controller state: TestStart
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Received a control message (98 bytes) in 1 iterations
[2021-08-03T07:54:36Z DEBUG netperf::controller] Controller state: CreateStreams { cookie: "b959b4f5-d437-4606-94ca-e70c51071899" }
[2021-08-03T07:54:36Z DEBUG netperf::controller] We should create data streams now
[2021-08-03T07:54:36Z DEBUG netperf::controller] Opening a data stream to (192.168.78.210:7559) ...
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 81 bytes
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Received a control message (27 bytes) in 1 iterations
[2021-08-03T07:54:36Z DEBUG netperf::controller] Data stream created to 192.168.78.210:7559
[2021-08-03T07:54:36Z WARN netperf::controller] Stream 0 has terminated with an error, we cannot fetch its total stream stats. This means that the results might be partial
[2021-08-03T07:54:36Z DEBUG netperf::controller] Controller state: CreateStreams { cookie: "b959b4f5-d437-4606-94ca-e70c51071899" }
[2021-08-03T07:54:36Z DEBUG netperf::controller] We should create data streams now
[2021-08-03T07:54:36Z DEBUG netperf::controller] Opening a data stream to (192.168.78.210:7559) ...
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Sent: 81 bytes
[2021-08-03T07:54:36Z DEBUG netperf::common::net_utils] Received a control message (51 bytes) in 1 iterations
Error: Access denied: Test already in-flight
Unfortunately, I don't have access to a window machine to debug this :(