Socket: Abort pending operations on shutdown #8758

sepalani · 2020-04-22T18:55:29Z

~~This PR will need a hardware test (similar #8389) to confirm this behaviour.~~

PR goal

This PR tries to fix inconsistencies regarding shutdown implementation (on a socket) and be as close as possible to what the Wii does (not sure about the GC behaviour).

What it fixes

It fixes crashes/hangs in some Just Dance games : https://dolp.in/i11910

What it doesn't fix

Dolphin not getting the right network interface on :
- Android (IP/Top: Add Android network interface #9191)
- MacOS (Top: Set port when connecting a socket to find the default interface #9214)
Return values of other network functions

Hardware test

I created 2 hardware tests:

one that fires shutdown on blocking operations
the second one that checks return values of network functions after shutdown was called

How-to run

Get the latest version of Dolphin (at least after IP/Top: Add SO_LINGER optname #9099)
Enable Dolphin debugging interface under Options > Config > Interface then tick Show Debugging UI
Enable the Dolphin Log window
In the Log configuration tab
- Tick "Write to File" in Logger Outputs
- Tick "OSREPORT" and "HLE"
- Set the verbosity level to Info or Debug
Make sure you run the ELF (not the DOL) hardware tests
(On top of that, you can also grab the result using netcat on your local IP address and the result port displayed at the end of the test)

Hardware tests results

Dolphin results are based on ~~this build #8796~~ latest master and #9191 for Android.

Results of the first hwtest

Results of the second hwtest

Analysis

Result value

NO STATE: Failed to reach wanted state
TIMEOUT or --: State reached but last task didn't finish
DEADLOCK: Same as timeout but cleanup didn't interrupt the ioctl call (i.e. impossible to join/stop thread)
shutdown / callback: return values (based on devkitPPC errno.h)

Code changes

The code was changed based on the wanted Wii results, my reasoning was done as follow:

The Wii does nothing and returns 0 for IP_PROTO_UDP
- based on IOS reverse-engineering
Adjust pending operations
- IOCTL_SO_ACCEPT:
  - hwtest-1: B/BIND/LISTEN/ACCEPT
  - #define EINVAL 22 /* Invalid argument */
- IOCTL_SO_CONNECT:
  - hwtest-1: B/CONNECT
  - #define ENETUNREACH 114 /* Network is unreachable */
- IOCTLV_SO_RECVFROM:
  - hwtest-1: B/CONNECT/RECV, B/BIND/LISTEN/ACCEPT'D/RECV
  - hwtest-2: B/BIND/LISTEN/ACCEPT'D/SHUT/RECV, B/CONNECT/SHUT/RECV
  - #define ENOTCONN 128 /* Socket is not connected */
- IOCTLV_SO_SENDTO:
  - hwtest-2: B/BIND/LISTEN/ACCEPT'D/SHUT/SEND, B/CONNECT/SHUT/SEND
  - #define ENOTCONN 128 /* Socket is not connected */

Ready to be reviewed & merged.

sepalani · 2020-04-26T08:40:55Z

I updated the error code based on this hardware test (still based on a connect call to a ubisoft server).

wii-soconnect-shutdown.zip

Some important points to mention:

I haven't handled the how parameter (i.e. might cause regression)
I need to write a test suite for all network calls to make sure, the error codes are correct and to know which calls are affected by the read and/or write end being closed by the shutdown call

sepalani · 2020-05-08T13:19:51Z

Very early WIP hwtest, I'll post a draft PR on the hwtest repository soon:
wii-shutdown.zip

Here are the results, I'll adjust this PR accordingly:
https://gist.github.com/sepalani/e0ef0b0c3b39ae4523c4f007fa23916d

Regarding the result value:

NO STATE: Failed to reach wanted state
TIMEOUT: State reached but last task didn't finish
DEADLOCK: Same as timeout but cleanup didn't interrupt the ioctl call
shutdown / callback: return values

sepalani · 2020-05-10T07:57:37Z

Test 1/2

I did some fine-tuning on the previous hwtest to fix some inconsistent behaviours:

I first added sleep before firing net_shutdown, now it matches the 1st hwtest I did (so-connect-shutdown) and doesn't timeout
I used www.example.com:80 as the TCP connection lives longer than on dns.google:443
I tidied the code logic a bit
wii-shutdown-v2.zip

The results:

I replaced the TIMEOUT value with : shutdown / -- return value
https://gist.github.com/sepalani/d1a9514cf410a139f280681bf76f8e99

Test 2/2

The other part of the test where I check return values of network functions after a shutdown call.
wii-shutdown-v2p2.zip

The results:
https://gist.github.com/sepalani/ccf2bc4d4104e5f68ac18ba2287cdd07

sepalani · 2020-05-10T16:39:39Z

@leoetlino
PR rebased, depends on #8796 and takes into account the how parameters.

This PR fixes Just Dance games: https://bugs.dolphin-emu.org/issues/11910

This PR should be thoroughly tested before being merged to be sure there is no network regression.

sepalani · 2020-05-26T13:11:55Z

I added hwtests results for the ASUS RoG Phone II and Linux (Parrot).

sepalani · 2020-06-02T09:04:50Z

I moved up the WiiSockMan::GetNetErrorCode call to be executed right after the shutdown call.

Still ready to be reviewed.

sepalani · 2020-06-18T19:01:46Z

Rebased on latest master. I tested it on some online games such as Super Smash Bros. Brawl, Mario Strikers Charged Football, DJHero and some Just Dance games and I didn't find any issue.

Ready to be reviewed & merged. Depends on #8796.

sepalani · 2020-09-01T15:52:34Z

Still ready to be reviewed & merged. This PR fixes https://bugs.dolphin-emu.org/issues/11910

As a side note, Nintendo have changed their server infrastructure and previously working games don't work anymore and that isn't related to this PR.

Many Wii games send duplicate HTTP Host headers (that's a well-known issue). But the current servers are stricter and don't accept them anymore resulting in Error Code 23400 (aka "HTTP 400 - Bad request").

MayImilae · 2020-09-12T10:13:24Z

So I have a mac so I can do the macOS testing for you. Can you walk me through it?

sepalani · 2020-09-12T13:07:30Z

@MayImilae Sure. You'll need to grab this build of dolphin and the first and second hardware test.

Then, make sure your computer has Internet and run the ELF files with the build of Dolphin you downloaded. There are two methods to grab the result. You can pick one of them or use them both.

Method 1

You can grab the result at the end of the test by connecting to your local IP address and the prompted port (it should be port 16784). I usually use the netcat command to grab the result and the tee command to redirect to a file.

# My local IP address was 192.168.1.7
# My output file was dolphin_hwtest_shutdown_v2rogII.txt
nc 192.168.1.7 16784 | tee dolphin_hwtest_shutdown_v2rogII.txt

Method 2

With this method the output of the test should appear in Dolphin log file:

Enable the Dolphin Log window
In the Log configuration tab
- Tick "Write to File" in Logger Outputs
- Tick "OSREPORT" and "HLE"
Make sure you run the ELF (not the DOL) hardware tests
.

These tests can take quite some time to run, by the way.

MayImilae · 2020-09-13T06:01:45Z

That PR build you pointed to has been merged, so... I'll just use latest master (5.0-12595). Also I'll just use Dolphin's logs since I'm familiar with them.

System specs:
MacBook Pro 13in mid-2018 with Touch Bar
macOS 10.15.4
Core i7-8559U @ 4.5ghz
Intel Iris Plus Graphics 655
16GB 2133MHz LPDDR3

Ok so, log settings are verbosity Info, write to file, and OSReport and OSHLE.

Dolphin settings are more or less normal. Things of note are OpenGL, 1x native, Scaled EFB Copy ON, Skip Presenting Duplicate Frames OFF.

Ok so, first test (wii-shutdown-v2) completed successfully.

Logs:

02:04:881 Core/HLE/HLE.cpp:124 I[HLE]: Patching printf 8002b310
02:04:881 Core/HLE/HLE.cpp:124 I[HLE]: Patching puts 8002b4e8

The second test (wii-shutdown-v2p2) did not complete. I tried it 4 times and it crashed each time, always late in the run. Verbosity info was exactly the same as the above v2 run that succeeded, so I enabled logging everything and let it run. This is the last line in that log.

51:09:779 Core/IOS/Device.cpp:101 I[IOS_WC24]: /dev/net/ip/top (fd 3) - IOCtl 0xe (in_size=0x8, out_size=0x0)

Nothing before that is unusual. Here's the full log.

wii-shutdown-v2p2.log.zip

So um, yea. Let me know if you want me to try anything.

JMC47 · 2020-09-13T07:00:09Z

9/10 is an A-, so I think it's good to go.

sepalani · 2020-09-13T08:02:02Z

@MayImilae My bad, it seems the OSREPORT log is missing. You'll need to enable Dolphin debugging interface under Options > Config > Interface then tick Show Debugging UI. The text you see on screen should now appear under the OSREPORT log.

I'll try on my end the second test to see if something has changed or if it's related to the Dolphin build. It can also be an OSX specific issue.

MayImilae · 2020-09-14T07:30:03Z

Ok! Here is some proper logs, this time dumped from terminal since the crashed run doesn't dump any logs.

wii-shutdown-v2 (successful): https://hastebin.com/eketabapac

wii-shutdown-v2p2 (crashed): https://hastebin.com/zaraganudo

sepalani · 2020-09-20T10:56:07Z

@MayImilae Thank you for the log and the files, there were quite useful.

After digging into the log, this is what I found so far:

There are some OSX specific errors which shouldn't matter for the test
- SO_SETSOCKOPT failed with error 22: Invalid argument with SO_LINGER on some sockets (seems related)
- SO_SETSOCKOPT failed with error 55: No buffer space available with SO_RCVBUF on all sockets from net_socket
Dolphin can't find the interface's IP (and that matters for the test as it prevents the use of bind)
- Android is also impacted
- Dolphin defaults to IP 10.0.1.30 (why?)
The GetSystemDefaultInterface function in Dolphin is mixing up endianness
- Host (little) endianness is used on Windows with the DefaultInterface structure (seems intended | Microsoft doc | converted to network endianness on result)
- Network endianness is used otherwise, (doesn't seem intended, according to ip(7) s_addr; /* address in network byte order */ see get_addr)

I'll try to see if I can fix the GetSystemDefaultInterface function and eventually add Android support. However, I don't know if I'll be able to add macOS support since I don't have one to test. Unfortunately, I wasn't able to identify the reason for the crash yet.

MayImilae · 2020-09-22T11:46:09Z

Let me know if there is anything else you'd like me to try on my mac! If I don't catch you posting here I'm always around on Dolphin's IRC.

OatmealDome · 2020-10-01T01:41:36Z

@sepalani I tested this PR on macOS 11 Big Sur.

The debugger tells me that the process exited with signal 13 (SIGPIPE). Apple's documentation (under "Use POSIX sockets efficiently") says a SIGPIPE will be issued if the connection is closed by default, and the application will be quit if it isn't handled or ignored.

I don't really have any experience in POSIX sockets, so sorry if this is wrong or not of any help.

JMC47 · 2020-10-09T11:14:49Z

Does this need to be rebased so that the crash fix is in? Would like to get this finally sorted out.

sepalani · 2020-10-09T11:39:06Z

@JMC47 I should but it won't fix the default network interface not being detected properly on macOS and Android. I'd like to sort these two things out, otherwise, these tests are meaningless for those platforms.

sepalani · 2020-10-24T07:03:57Z

I updated the Android results based on this PR: #9191

JMC47 · 2020-10-24T07:14:22Z

So the only thing left is figuring out macOS now?

sepalani · 2020-10-24T15:48:57Z

@JMC47 Yes, indeed.

I suspect there is something odd in the Linux part of the code. Part of the hardware test for both Linux and Mac shows a NO STATE result. It mustn't happen in the shutdown(NONE) (i.e. I don't call shutdown) part of the test. That's where I perform simple network operations which shouldn't fail.

sepalani · 2020-10-31T12:19:07Z

@JMC47
I found the issue for Linux and I fixed it without noticing in #9099. The SO_LINGER constant was defined with a different value, that's probably the issue on Mac too. Both Android and Linux results are now on par and I expect the same for macOS.

@OatmealDome @MayImilae
Could you please retry the two hardware tests on macOS with the latest version of Dolphin?

You'll need to:

Get the latest version of Dolphin (at least after IP/Top: Add SO_LINGER optname #9099)
Enable Dolphin debugging interface under Options > Config > Interface then tick Show Debugging UI
Enable the Dolphin Log window
In the Log configuration tab
- Tick "Write to File" in Logger Outputs
- Tick "OSREPORT" and "HLE"
- Set the verbosity level to Info or Debug
Make sure you run the ELF (not the DOL) hardware tests

OatmealDome · 2020-10-31T23:40:34Z

@sepalani I ran both tests on macOS 11 Big Sur beta 10, Dolphin 5.0-12946.

first

second

sepalani · 2020-11-01T09:21:15Z

@OatmealDome
Thanks a lot. Sadly, it seems there are still bind issues on macOS. At least we have complete tests without a crash.

@leoetlino @JMC47
I updated the PR description with all the results. Feel free to merge this PR in its current states since it fixes the shutdown behaviour but it won't fix other network related issues on Android and macOS.

sepalani force-pushed the so-shutdown branch from b32df49 to 81b4b57 Compare April 26, 2020 08:30

leoetlino added the needs HW test or RE label Apr 27, 2020

sepalani force-pushed the so-shutdown branch 2 times, most recently from dd2947f to ff2915f Compare May 10, 2020 16:31

sepalani force-pushed the so-shutdown branch from ff2915f to 595f16e Compare June 2, 2020 09:00

sepalani force-pushed the so-shutdown branch from 595f16e to 791448d Compare June 18, 2020 18:33

sepalani force-pushed the so-shutdown branch from 791448d to 65f8024 Compare June 19, 2020 04:47

sepalani force-pushed the so-shutdown branch from 65f8024 to 820d525 Compare July 3, 2020 19:20

Socket: Abort pending operations on shutdown

c63ac38

sepalani force-pushed the so-shutdown branch from 820d525 to c63ac38 Compare September 1, 2020 15:38

sepalani mentioned this pull request Oct 1, 2020

Socket: Set SO_NOSIGPIPE on macOS #9123

Merged

OatmealDome mentioned this pull request Nov 1, 2020

Top: Set port when connecting a socket to find the default interface #9214

Merged

leoetlino approved these changes Nov 2, 2020

View reviewed changes

leoetlino merged commit 5b9cd83 into dolphin-emu:master Nov 2, 2020
10 checks passed

sepalani deleted the so-shutdown branch November 7, 2020 09:10

Socket: Abort pending operations on shutdown #8758

Socket: Abort pending operations on shutdown #8758

sepalani commented Apr 22, 2020 •

edited

sepalani commented Apr 26, 2020

sepalani commented May 8, 2020 •

edited

sepalani commented May 10, 2020 •

edited

sepalani commented May 10, 2020 •

edited

sepalani commented May 26, 2020

sepalani commented Jun 2, 2020

sepalani commented Jun 18, 2020

sepalani commented Sep 1, 2020

MayImilae commented Sep 12, 2020

sepalani commented Sep 12, 2020

MayImilae commented Sep 13, 2020 •

edited

JMC47 commented Sep 13, 2020

sepalani commented Sep 13, 2020

MayImilae commented Sep 14, 2020

sepalani commented Sep 20, 2020

MayImilae commented Sep 22, 2020

OatmealDome commented Oct 1, 2020

JMC47 commented Oct 9, 2020

sepalani commented Oct 9, 2020

sepalani commented Oct 24, 2020

JMC47 commented Oct 24, 2020

sepalani commented Oct 24, 2020

sepalani commented Oct 31, 2020

OatmealDome commented Oct 31, 2020

sepalani commented Nov 1, 2020 •

edited

Socket: Abort pending operations on shutdown #8758

Socket: Abort pending operations on shutdown #8758

Conversation

sepalani commented Apr 22, 2020 • edited

PR goal

What it fixes

What it doesn't fix

Hardware test

How-to run

Hardware tests results

Results of the first hwtest

Results of the second hwtest

Analysis

Result value

Code changes

sepalani commented Apr 26, 2020

sepalani commented May 8, 2020 • edited

sepalani commented May 10, 2020 • edited

Test 1/2

Test 2/2

sepalani commented May 10, 2020 • edited

sepalani commented May 26, 2020

sepalani commented Jun 2, 2020

sepalani commented Jun 18, 2020

sepalani commented Sep 1, 2020

MayImilae commented Sep 12, 2020

sepalani commented Sep 12, 2020

Method 1

Method 2

MayImilae commented Sep 13, 2020 • edited

JMC47 commented Sep 13, 2020

sepalani commented Sep 13, 2020

MayImilae commented Sep 14, 2020

sepalani commented Sep 20, 2020

MayImilae commented Sep 22, 2020

OatmealDome commented Oct 1, 2020

JMC47 commented Oct 9, 2020

sepalani commented Oct 9, 2020

sepalani commented Oct 24, 2020

JMC47 commented Oct 24, 2020

sepalani commented Oct 24, 2020

sepalani commented Oct 31, 2020

OatmealDome commented Oct 31, 2020

sepalani commented Nov 1, 2020 • edited

sepalani commented Apr 22, 2020 •

edited

sepalani commented May 8, 2020 •

edited

sepalani commented May 10, 2020 •

edited

sepalani commented May 10, 2020 •

edited

MayImilae commented Sep 13, 2020 •

edited

sepalani commented Nov 1, 2020 •

edited