Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Co-op issue on MGS:PW #14130

Closed
anr2me opened this issue Feb 13, 2021 · 9 comments · Fixed by #14140
Closed

Co-op issue on MGS:PW #14130

anr2me opened this issue Feb 13, 2021 · 9 comments · Fixed by #14140
Labels
Networking / adhoc
Milestone
v1.12.0

Comments

@anr2me
Copy link
Collaborator

anr2me commented Feb 13, 2021 •
edited
Loading

Reported through forum's PM, MGS:PW can't play Android vs PC, and after trying to reproduce it i found 2 issues

What happens?

1). If PC host, Android can't see the game room because for some unknown reason the one on Android is always using port 1024 regardless of Port Offset

37:33:582 idle0        D[SCENET]: hle\scenetadhoc.cpp:6015 HELLO Dump:
          00000000  04 01 02 00 be 09 00 00 49 4d 41 4e 4f 5f 4b 00  ........IMANO_K.
          00000010  00 00 00 00 00 00 00 00 3b b5 32 01 1b ff        ........;.2...
37:33:582 idle0        D[SCENET]: hle\scenetadhoc.cpp:1572 sceNetAdhocPdpSend[1:14099](BC): Sent 35 bytes to 192.168.8.102:14099
37:33:582 idle0        D[SCENET]: hle\scenetadhoc.cpp:1572 sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.102:14099
37:33:817 idle0        D[SCENET]: hle\scenetadhoc.cpp:1743 sceNetAdhocPdpRecv[1:14099]: Received 1 bytes from 192.168.8.102:1024
37:34:084 idle0        D[SCENET]: hle\scenetadhoc.cpp:1572 sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.102:14099
37:34:330 idle0        D[SCENET]: hle\scenetadhoc.cpp:1743 sceNetAdhocPdpRecv[1:14099]: Received 1 bytes from 192.168.8.102:1024
37:34:588 idle0        D[SCENET]: hle\scenetadhoc.cpp:6015 HELLO Dump:
          00000000  04 01 02 00 be 09 00 00 49 4d 41 4e 4f 5f 4b 00  ........IMANO_K.
          00000010  00 00 00 00 00 00 00 00 3b b5 32 01 1b ff        ........;.2...

2). If Android host, and PC joined, the one on PC failed to start the mission, seems to be AdhocMatching issue

What should happen?

Multiplayer co-op should works

What hardware, operating system, and PPSSPP version? On desktop and mobile phone, GPU matters for graphical issues.

Please test newest version in https://buildbot.orphis.net/ppsspp/

PPSSPP v1.11.1-4-gd23bef152
@anr2me
Copy link
Collaborator Author

anr2me commented Feb 13, 2021 •
edited
Loading

This port 1024 is really weird... because the socket is created within AdhocMatchingStart and it was created the same way as host & join, so i wondered why it use different port between host & join on android side...

Or it might be a different app on Android side broadcasting to port 14099 from port 1024 and got received by PPSSPP and made AdhocMatching confused...

Apparently port 1024 issue also happened when Android host sometimes :( i did managed to join the room hosted by Android once when trying to reproduce it, so this issue might be random.

This is the logs when PC tried to search room hosted by Android and PC unable to see the room:

24:55:544 Main         W[SCENET]: hle\scenetadhoc.cpp:4721 UNTESTED sceNetAdhocMatchingStart(1, 24, 8192, 24, 0, 0, 00000000) at 0886d064
24:55:544 Main         I[SCENET]: hle\scenetadhoc.cpp:1223 sceNetAdhocPdpCreate(28:b5:ff:ca:1f:ef, 4099, 1024, 0) at 0886d064
24:55:545 Main         D[SCENET]: hle\scenetadhoc.cpp:1323 00000001=sceNetAdhocMatchingStart(1, 24, 8192, 24, 0, 0, 00000000): success
24:55:545 idle0        I[SCENET]: hle\scenetadhoc.cpp:6965 EventLoop: Begin of EventLoop[1] Thread
24:55:545 idle0        I[SCENET]: hle\scenetadhoc.cpp:7111 InputLoop: Begin of InputLoop[1] Thread
24:55:546 snd_thread_s D[SCENET]: hle\scenetadhoc.cpp:1572 sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.102:14099
24:55:562 Main         D[SCENET]: hle\scenetadhoc.cpp:5092 UNTESTED sceNetAdhocMatchingGetMembers(1, [09fbf920]=146021492, 00000000) at 0886be4c
24:55:562 Main         D[SCENET]: hle\scenetadhoc.cpp:5140 MemberList [Connected: 1]
24:55:562 Main         D[SCENET]: hle\scenetadhoc.cpp:5092 UNTESTED sceNetAdhocMatchingGetMembers(1, [09fbf920]=12, 09fbf928) at 0886c2a0
24:55:562 Main         D[SCENET]: hle\scenetadhoc.cpp:5168 MemberSelf [28:b5:ff:ca:1f:ef]
24:55:562 Main         D[SCENET]: hle\scenetadhoc.cpp:5286 MemberList [Requested: 1][Discovered: 1]
24:55:562 Main         D[SCENET]: hle\scenet.cpp:697 0=sceWlanGetEtherAddr(09fbd720)
24:55:989 idle0        D[SCENET]: hle\scenetadhoc.cpp:1743 sceNetAdhocPdpRecv[1:14099]: Received 35 bytes from 192.168.8.102:1024
24:56:000 idle0        D[SCENET]: hle\scenetadhoc.cpp:1743 sceNetAdhocPdpRecv[1:14099]: Received 1 bytes from 192.168.8.102:1024
24:56:055 idle0        D[SCENET]: hle\scenetadhoc.cpp:1572 sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.102:14099
24:56:483 idle0        D[SCENET]: hle\scenetadhoc.cpp:1743 sceNetAdhocPdpRecv[1:14099]: Received 1 bytes from 192.168.8.102:1024
24:56:548 idle0        D[SCENET]: hle\scenetadhoc.cpp:1572 sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.102:14099

The port on both side (sender and receiver) supposed to be the same when working correctly (both use port offset 10000)

@ghost
Copy link

ghost commented Feb 13, 2021 •
edited by ghost
Loading

Versus also is not working PC to PC but only if there is some lantancy involved (?) not sure .
Versus works Android to PC but Android got to host.
Coop just straight disconnects though.

@anr2me
Copy link
Collaborator Author

anr2me commented Feb 13, 2021 •
edited
Loading

It's strage that i can't see anything in the Logcat when debugging from Android Studio... i'm getting this error when AS tried to attach debugger

23:24	Error running 'android'
			Invalid argument : Argument invalid
			[port]

even when i didn't get that error, and saw this

Connected to the target VM, address: 'localhost:40784', transport: 'socket'

i still can't see anything logged in the Logcat :( this is strange.. may be because i'm running out of free space on internal storage? this phone only have 32gb storage

if i did adb logcat -s DEBUG PPSSPPNativeActivity PPSSPP NativeGLView NativeRenderer NativeSurfaceView PowerSaveModeReceiver InputDeviceState from cmd line, i'm getting EOF and adb exited afterward, doing adb logcat -c doesn't makes any difference either.

02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] Context switch: ringbuf -> idle0 (758->272, pc: 09097824->08000000, thread delayed) +21us
02-13 23:49:20.939  7983  8052 I PPSSPP  : [CPU] Entering GE interrupt handler 08b44eac
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] Context switch: idle0 -> Main (272->278, pc: 08000000->08b42780, left interrupt) +998us
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] Context switch: Main -> idle0 (278->272, pc: 0887b704->08000000, vblank start waited) +7us
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] Context switch: idle0 -> ringbuf (272->758, pc: 08000000->09097824, thread delay finished) +4us
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] 0=sceKernelSetEventFlag(757, ffffffff)
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] 0=sceKernelDelayThreadCB(000003e8): delaying 1010 usecs
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] Context switch: ringbuf -> idle0 (758->272, pc: 09097824->08000000, thread delayed) +17us
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] Context switch: idle0 -> soundbuf (272->761, pc: 08000000->090bd7d8, audio drain) +3us
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] sceKernelSignalSema(754, 1) (count: 0 -> 1)
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] 0=sceKernelWaitSema(339, 1, 167542368)
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEKERNEL] sceKernelSignalSema(339, 1) (count: 0 -> 1)
02-13 23:49:20.939  7983  8052 I PPSSPP  : [SCEAUDIO] 00000800 = sceAudioOutputPannedBlocking(00000005, 00008000, 00008000, 09f17180)
02-13 23:49:20.940  7983  8052 I PPSSPP  : [SCEKERNEL] Context switch: soundbuf -> decatr (761->760, pc: 090bd7d8->09098a9c, blocking audio) +13us
read: unexpected EOF!

I can't even trigger the breakpoint i put inside sceNetAdhocPdpCreate to findout how it gets port 1024 from original port of 4099 and port offset = 10000

Edit: breakpoint is working now, and i found no problem on sceNetAdhocPdpCreate so this is confusing

@anr2me
Copy link
Collaborator Author

anr2me commented Feb 13, 2021 •
edited
Loading

This is the log from Android, it's sending data from port 14099 to PC port 14099 which is correct

2021-02-14 01:01:34.534 20496-24474/org.ppsspp.ppsspp I/PPSSPP: [SCENET] HELLO Dump:
              00000000  04 01 02 00 a2 45 00 00 49 4d 41 4e 4f 5f 4b 00  .....E..IMANO_K.
              00000010  00 00 00 00 00 00 00 00 3b b5 32 01 04 ff        ........;.2...
2021-02-14 01:01:34.535 20496-24474/org.ppsspp.ppsspp I/PPSSPP: [SCENET] sceNetAdhocPdpSend[1:14099](BC): Sent 35 bytes to 192.168.8.101:14099
2021-02-14 01:01:34.535 20496-24474/org.ppsspp.ppsspp I/PPSSPP: [SCENET] sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.101:14099
2021-02-14 01:01:35.357 20496-24474/org.ppsspp.ppsspp I/PPSSPP: [SCENET] sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.101:14099

But for some reason, upon arrival, the one on PC is detecting the source port to be 56560 (where it should be 4099), thus when replied the one on android never received the reply because it's going to the wrong port.

04:47:754 idle0        D[SCENET]: HLE\sceNetAdhoc.cpp:1575 sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.102:14099
04:47:765 idle0        D[SCENET]: HLE\sceNetAdhoc.cpp:1746 sceNetAdhocPdpRecv[1:14099]: Received 35 bytes from 192.168.8.102:1024
04:47:765 idle0        D[SCENET]: HLE\sceNetAdhoc.cpp:7274 InputLoop[1]: Unknown Port[70:7b:67:74:51:21:56560] (Recved=0, Length=35)
04:47:776 idle0        D[SCENET]: HLE\sceNetAdhoc.cpp:1746 sceNetAdhocPdpRecv[1:14099]: Received 1 bytes from 192.168.8.102:1024
04:47:776 idle0        D[SCENET]: HLE\sceNetAdhoc.cpp:7274 InputLoop[1]: Unknown Port[70:7b:67:74:51:21:56560] (Recved=0, Length=1)
04:48:251 idle0        D[SCENET]: HLE\sceNetAdhoc.cpp:1575 sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.102:14099
04:48:582 idle0        D[SCENET]: HLE\sceNetAdhoc.cpp:1746 sceNetAdhocPdpRecv[1:14099]: Received 1 bytes from 192.168.8.102:1024
04:48:582 idle0        D[SCENET]: HLE\sceNetAdhoc.cpp:7274 InputLoop[1]: Unknown Port[70:7b:67:74:51:21:56560] (Recved=0, Length=1)
04:48:753 idle0        D[SCENET]: HLE\sceNetAdhoc.cpp:1575 sceNetAdhocPdpSend[1:14099](BC): Sent 1 bytes to 192.168.8.102:14099

I have no idea how the port 14099 ended became 1024, and it seems to only happened when receiving data from android, while PC to PC have the correct port being detected (at least on localhost).

Or may be i have a buggy OS? i did update my OS (both Android 10 and Win10) recently.

PS: 56560 + 10000 = 66560, 66560 % 65536(total 16bit port) = 1024, so 1024 - 10000 will be wrapped back to 56560 as uint16

Edit: i think i found the problem or may be not :(

@anr2me
Copy link
Collaborator Author

anr2me commented Feb 13, 2021 •
edited
Loading

Versus also is not working PC to PC but only if there is some lantancy involved (?) not sure .
Versus works Android to PC but Android got to host.
Coop just straight disconnects though.

I'm not sure whether the issue resides on Windows or Android, but detecting the wrong port like this will certainly cause communication issue on all games that use PDP/UDP be cause after receiving data the game will send the reply to the wrong port thus that reply ended never received, since AdhocMatching is using PDP it will certainly have issue too, although it's a bit random where sometimes it can detects the port correctly.

I will try to create test build later that will shows warning on screen if there is incoming AdhocMatching data that came from a wrong port, and tester will need to test this on PC vs PC, and Android vs Android, so we can at least know whether this wrong detection only happened on windows or android too.

@ghost
Copy link

ghost commented Feb 13, 2021 •
edited by ghost
Loading

I wonder if this is why Patapon 3 and God Eater 2 (and 1?) got issues with the port offset too...
At least with God Eater this happened with multiple instances on 1 PC.
Patapon 3 needs a port offset above 5000 last time I tried.

@anr2me
Copy link
Collaborator Author

anr2me commented Feb 13, 2021 •
edited
Loading

This wrong port detection have nothing to do with port offset, changing it to any value will still be detected as 1024, even when MGS:PW create the 2nd socket (created when the mission started, which use port 4100) the data also detected as coming from 1024, just like the one from the other socket (AdhocMatching socket that use port 4099), so this 1024/56560 seems to be fixed number not sure where it came from.

I've tried to zeroing/memset the sockaddr_in arg and set it's length correctly upon calling recvfrom but the output source port is still wrong :( this is confusing...

anr2me added a commit to anr2me/ppsspp that referenced this issue Feb 14, 2021
@anr2me
Give more time for the socket to be bound properly before being used …
f1f516e 
…(sometimes it takes a few seconds before the port detected correctly on receiver side). Fix hrydgard#14130 most of the time, but may not be the best solution.
@anr2me anr2me mentioned this issue Feb 14, 2021
Merged
anr2me added a commit to anr2me/ppsspp that referenced this issue Feb 14, 2021
@anr2me
Give more time for the socket to be bound properly before being used …
909b5bf 
…(sometimes it takes a few seconds before the port detected correctly on receiver side). Fix hrydgard#14130 most of the time, but may not be the best solution.
anr2me added a commit to anr2me/ppsspp that referenced this issue Feb 15, 2021
@anr2me
Give more time for the socket to be bound properly before being used …
7fa0c0b 
…(sometimes it takes a few seconds before the port detected correctly on receiver side). Fix hrydgard#14130 most of the time, but may not be the best solution.
anr2me added a commit to anr2me/ppsspp that referenced this issue Feb 15, 2021
@anr2me
Give more time for the socket to be bound properly before being used …
43d48af 
…(sometimes it takes a few seconds before the port detected correctly on receiver side). Fix hrydgard#14130 most of the time, but may not be the best solution.
@ghost
Copy link

ghost commented Feb 20, 2021 •
edited by ghost
Loading

This wrong port detection have nothing to do with port offset, changing it to any value will still be detected as 1024, even when MGS:PW create the 2nd socket (created when the mission started, which use port 4100) the data also detected as coming from 1024, just like the one from the other socket (AdhocMatching socket that use port 4099), so this 1024/56560 seems to be fixed number not sure where it came from.

I've tried to zeroing/memset the sockaddr_in arg and set it's length correctly upon calling recvfrom but the output source port is still wrong :( this is confusing...

From the other PR it seems that it is port offset related...
Using 10000 as a port offset does seem like a good choise but its a really high number for some routers to open.

@anr2me
Copy link
Collaborator Author

anr2me commented Feb 20, 2021 •
edited
Loading

Routers shouldn't have any issue opening any port (after all routers are gateway that can provide access to all ports), unless that port is already used for something else.
And Port Offset related issue means it's restricted by the OS (requires admin/sudo) or the port is exclusively taken by other app.

But the issue i had is a bit strange, if Port Offset is 5000 using bind on a specific port will be success and retrieving the binded port using getsockname will also shows that specific port.
However, when the socket is used for sending UDP data, the source port ended to be a different port (a random high port, usually used when using port 0 which let the system assign any available port), and i can't find any documentation that mentions this behavior where requested port being replaced with a random port, usually bind will return an error if the requested port can't be binded instead of silently replacing the port with a random port.
And another strange thing is, using Port Offset 10000 didn't have this issue...
Also, doing netstat -antul before running PPSSPP from adb shell didn't show any port within 5000-10000 range, so it's not used by other app (taken ports on my phone is 68, and some 33k+)

I'm not sure if this issue only happened on my OS (Realme's OS based on Android 10) or other Android variants too.

anr2me added a commit to anr2me/ppsspp that referenced this issue Feb 21, 2021
@anr2me
Making sure the port is bound to an interface when using bind with IN…
e1f6632 
…ADDR_ANY. Seems to fix hrydgard#14130
anr2me added a commit to anr2me/ppsspp that referenced this issue Feb 21, 2021
@anr2me
Making sure the port is bound to an interface when using bind with IN…
4ee08ef 
…ADDR_ANY. Seems to fix hrydgard#14130
@unknownbrackets unknownbrackets added this to the v1.12.0 milestone Feb 22, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Networking / adhoc
Projects
None yet
Milestone
v1.12.0
2 participants
@unknownbrackets @anr2me