gRPC C++ Android 'Security handshake failed' issue

[Artem V]

Greetings,

We are trying to port our gRPC C++ solution we use for Unreal Engine 5 to Android. We use gRPC version 1.35 due to Unreal Engine restrictions. Our loading process works fine on Windows but fails on Android with ‘Security handshake failed’. I’ll appreciate any help to find out why this happens and how can I fix it.

This what I can see in gRPC logs. “Bad address” error seems odd because domain and target address are the same as in working Windows build. Please let me know if you need more info.

LogPlayLevel: UAT: 02-17 16:23:05.434 14296 14912 D UE : [2023.02.17-12.23.05:434][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\tcp_client_posix.cc::143::1: CLIENT_CONNECT: ipv4:xx.xxx.xxx.xxx:443: on_writable: error="No Error" LogPlayLevel: UAT: 02-17 16:23:05.434 14296 14912 D UE : [2023.02.17-12.23.05:434][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\timer_generic.cc::470::1: TIMER 0x78fe0e7d90: CANCEL pending=true LogPlayLevel: UAT: 02-17 16:23:05.434 14296 14889 D UE : [2023.02.17-12.23.05:434][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\timer_generic.cc::719::1: TIMER CHECK BEGIN: now=5010 next=9223372036854775807 tls_min=1410 glob_min=5013 LogPlayLevel: UAT: 02-17 16:23:05.434 14296 14889 D UE : [2023.02.17-12.23.05:434][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\timer_generic.cc::741::1: TIMER CHECK END: r=1; next=5013 LogPlayLevel: UAT: 02-17 16:23:05.434 14296 14912 D UE : [2023.02.17-12.23.05:434][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\tcp_client_posix.cc::107::1: CLIENT_CONNECT: ipv4:xx.xxx.xxx.xxx:443: on_alarm: error="Cancelled" LogPlayLevel: UAT: 02-17 16:23:05.434 14296 14889 D UE : [2023.02.17-12.23.05:434][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\timer_manager.cc::188::1: sleep for a 3 milliseconds LogPlayLevel: UAT: 02-17 16:23:05.434 14296 14912 D UE : [2023.02.17-12.23.05:434][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\channel\handshaker.cc::99::1: handshake_manager 0x78fe5300a0: adding handshaker http_connect [0x78fe540010] at index 0 LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\tsi\ssl_transport_security.cc::226::1: HANDSHAKE START - before SSL initialization - PINIT LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\tsi\ssl_transport_security.cc::226::1: LOOP - before SSL initialization - PINIT LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\tsi\ssl_transport_security.cc::226::1: LOOP - SSLv3/TLS write client hello - TWCH LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\channel\handshaker.cc::99::1: handshake_manager 0x78fe5300a0: adding handshaker security [0x78fe36c800] at index 1 LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\timer_generic.cc::367::1: TIMER 0x78fe530108: SET 21100 now 5011 call 0x78fe530138[0x7969167388] LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\timer_generic.cc::404::1: .. add to shard 12 with queue_deadline_cap=6008 => is_first_timer=false LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\channel\handshaker.cc::129::1: handshake_manager 0x78fe5300a0: error="No Error" shutdown=0 index=0, args={endpoint=0x78fd80e780, args=0xb4000079c26c32e0 {size=9: grpc.primary_user_agent=grpc-c++/1.35.0, grpc.client_channel_factory=0x7920c00c20, grpc.channel_credentials=0x7920510740, grpc.server_uri=dns:///api-studio.project.ai, grpc.subchannel_pool=0x796cd3b200, grpc.default_authority=api-studio.project.ai, grpc.http2_scheme=https, grpc.security_con nector=0x7920ed3200, grpc.subchannel_address=ipv4:xx.xxx.xxx.xxx:443}, read_buffer=0xb400007951a27c00 (length=0), exit_early=0} LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\channel\handshaker.cc::176::1: handshake_manager 0x78fe5300a0: calling handshaker http_connect [0x78fe540010] at index 0 LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\channel\handshaker.cc::129::1: handshake_manager 0x78fe5300a0: error="No Error" shutdown=0 index=1, args={endpoint=0x78fd80e780, args=0xb4000079c26c32e0 {size=9: grpc.primary_user_agent=grpc-c++/1.35.0, grpc.client_channel_factory=0x7920c00c20, grpc.channel_credentials=0x7920510740, grpc.server_uri=dns:///api-studio.project.ai, grpc.subchannel_pool=0x796cd3b200, grpc.default_authority=api-studio.project.ai, grpc.http2_scheme=https, grpc.security_con nector=0x7920ed3200, grpc.subchannel_address=ipv4:xx.xxx.xxx.xxx:443}, read_buffer=0xb400007951a27c00 (length=0), exit_early=0} LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\channel\handshaker.cc::176::1: handshake_manager 0x78fe5300a0: calling handshaker security [0x78fe36c800] at index 1 LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\tcp_posix.cc::1572::1: WRITE 0x78fd80e780 (peer=ipv4:xx.xxx.xxx.xxx:443) LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\tcp_posix.cc::1576::0: DATA: 16 03 01 01 3b 01 00 01 37 03 03 a7 82 6d 13 b6 68 b0 a4 fc 05 ca 2d 5b 3f fb 81 c8 90 4e 38 12 35 5e 22 5d 68 b8 98 7b 32 c9 e4 20 c3 b6 58 bf e0 3a 8a a6 f8 b3 7c 5e 04 da d8 6b eb 33 aa e3 9e 2f 60 08 4a e1 87 f0 5c b8 92 60 00 10 13 02 13 03 13 01 c0 2b c0 2c c0 2f c0 30 00 ff 01 00 00 de 00 00 00 1a 00 18 00 00 15 61 70 69 2d 73 74 75 64 69 6f 2e 69 6e 77 6f 72 6c 64 2e 61 69 00 0b 00 04 03 00 01 02 00 0a 00 0 4 00 02 00 17 00 23 00 00 33 74 00 00 00 10 00 0e 00 0c 08 67 72 70 63 2d 65 78 70 02 68 32 00 16 00 00 00 17 00 00 00 0d 00 30 00 2e 04 03 05 03 06 03 08 07 08 08 08 09 08 0a 08 0b 08 04 08 05 08 06 04 01 05 01 06 01 03 03 02 03 03 01 02 01 03 02 02 02 04 02 05 02 06 02 00 2b 00 05 04 03 04 03 03 00 2d 00 02 01 01 00 33 00 47 00 45 00 17 00 41 04 b0 53 f2 a4 ff 0a 5a 52 84 9e f3 76 5c d6 f5 ab 95 94 31 d4 fc b8 06 05 9e 97 9e aa d0 f6 db 57 28 31 9b 88 88 d8 e7 5b 38 63 c6 a3 79 LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\tcp_posix.cc::1622::1: write: {"created":"@1676636585.435700264","description":"Bad address","errno":14,"fd":152,"file":"C:\Projects\project\grpc\src\core\lib\iomgr\tcp_posix.cc","file_line":1488,"grpc_status":14,"os_error":"Bad address","syscall":"sendmsg","target_address":"ipv4:xx.xxx.xxx.xxx:443"} LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\security\transport\security_handshaker.cc::184::0: Security handshake failed: {"created":"@1676636585.435747295","description":"Handshake write failed","file":"C:\Projects\project\grpc\src\core\lib\security\transport\security_handshaker.cc","file_line":431,"referenced_errors":[{"created":"@1676636585.435700264","description":"Bad address","errno":14,"fd":152,"file":"C:\Projects\project\grpc\src\core\lib\iomgr\tcp_posix.cc","file_line":1488,"grpc_sta tus":14,"os_error":"Bad address","syscall":"sendmsg","target_address":"ipv4:xx.xxx.xxx.xxx:443"}]} LogPlayLevel: UAT: 02-17 16:23:05.435 14296 14912 D UE : [2023.02.17-12.23.05:435][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\channel\handshaker.cc::129::1: handshake_manager 0x78fe5300a0: error={"created":"@1676636585.435747295","description":"Handshake write failed","file":"C:\Projects\project\grpc\src\core\lib\security\transport\security_handshaker.cc","file_line":431,"referenced_errors":[{"created":"@1676636585.435700264","description":"Bad address","errno":14,"fd":152,"file":"C:\Projects\project\grpc\src\core\lib\iomgr\tcp_posix.cc","file_line":1488,"grpc_status":14," os_error":"Bad address","syscall":"sendmsg","target_address":"ipv4:xx.xxx.xxx.xxx:443"}]} shutdown=0 index=2, args={endpoint=(nil), args=(nil) {size=0: }, read_buffer=(nil) (length=0), exit_early=0} LogPlayLevel: UAT: 02-17 16:23:05.436 14296 14912 D UE : [2023.02.17-12.23.05:436][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\channel\handshaker.cc::162::1: handshake_manager 0x78fe5300a0: handshaking complete -- scheduling on_handshake_done with error={"created":"@1676636585.435747295","description":"Handshake write failed","file":"C:\Projects\project\grpc\src\core\lib\security\transport\security_handshaker.cc","file_line":431,"referenced_errors":[{"created":"@1676636585.435700264","description":"Bad address","errno":14,"fd":152,"file":"C:\Projects\project\grpc\src\core\l ib\iomgr\tcp_posix.cc","file_line":1488,"grpc_status":14,"os_error":"Bad address","syscall":"sendmsg","target_address":"ipv4:xx.xxx.xxx.xxx:443"}]} LogPlayLevel: UAT: 02-17 16:23:05.436 14296 14912 D UE : [2023.02.17-12.23.05:436][279]LogProject: GRPC C:\Projects\project\grpc\src\core\lib\iomgr\timer_generic.cc::470::1: TIMER 0x78fe530108: CANCEL pending=true LogPlayLevel: UAT: 02-17 16:23:05.436 14296 14912 D UE : [2023.02.17-12.23.05:436][279]LogProject: GRPC C:\Projects\project\grpc\src\core\ext\filters\client_channel\subchannel.cc::1060::1: Connect failed: {"created":"@1676636585.435747295","description":"Handshake write failed","file":"C:\Projects\project\grpc\src\core\lib\security\transport\security_handshaker.cc","file_line":431,"referenced_errors":[{"created":"@1676636585.435700264","description":"Bad address","errno":14,"fd":152,"file":"C:\Projects\project\grpc\src\core\lib\iomgr\tcp_posix.cc","file_line":1488,"grpc_status":14,"os_err or":"Bad address","syscall":"sendmsg","target_address":"ipv4:xx.xxx.xxx.xxx:443"}]}

​

[Richard Belleville]

> ipv4:xx.xxx.xxx.xxx:443

Did you censor the logs or is this really your target address? If this is not censored, then this is clearly not a valid ipv4 address.

[Artem V]

Hi Richard. Yes this is censored ipv4. As I mentioned above 'domain and target address are the same as in working Windows build'. Adress is totally fine the problem is something else.

среда, 22 февраля 2023 г. в 22:50:01 UTC+4, Richard Belleville:

[Artem V]

Update:

I've updated grpc to v1.53 and still getting the same error:

LogPlayLevel: UAT: 02-23 22:51:34.793 23217 23654 D UE      : [2023.02.23-18.51.34:793][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\transport\handshaker.cc::100::1: handshake_manager 0x79210acd40: error=OK shutdown=0 index=1, args={endpoint=0x7921e36a00, args={grpc.client_channel_factory=0x7921d34480, grpc.default_authority=api-studio.project.ai, grpc.http2_scheme=https, grpc.internal.channel_credentials=0x79211bf500, grpc.internal.event_engine=0x7921d34a10, grpc.internal.security_connector=0x7922014680, grpc.internal.subchannel_pool=0x796dfcbef0, grpc.primary_user_agent=g

rpc-c++/1.53.0-pre1, grpc.resource_quota=0x796dfcbda0, grpc.server_uri=dns:///api-studio.project.ai}, read_buffer=0xb40000796b7ef240 (length=0), exit_early=0}

LogPlayLevel: UAT: 02-23 22:51:34.793 23217 23654 D UE      : [2023.02.23-18.51.34:793][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\transport\handshaker.cc::146::1: handshake_manager 0x79210acd40: calling handshaker http_connect [0x7921df0010] at index 1

LogPlayLevel: UAT: 02-23 22:51:34.794 23217 23654 D UE      : [2023.02.23-18.51.34:793][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\transport\handshaker.cc::100::1: handshake_manager 0x79210acd40: error=OK shutdown=0 index=2, args={endpoint=0x7921e36a00, args={grpc.client_channel_factory=0x7921d34480, grpc.default_authority=api-studio.project.ai, grpc.http2_scheme=https, grpc.internal.channel_credentials=0x79211bf500, grpc.internal.event_engine=0x7921d34a10, grpc.internal.security_connector=0x7922014680, grpc.internal.subchannel_pool=0x796dfcbef0, grpc.primary_user_agent=g

rpc-c++/1.53.0-pre1, grpc.resource_quota=0x796dfcbda0, grpc.server_uri=dns:///api-studio.project.ai}, read_buffer=0xb40000796b7ef240 (length=0), exit_early=0}

LogPlayLevel: UAT: 02-23 22:51:34.794 23217 23654 D UE      : [2023.02.23-18.51.34:794][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\transport\handshaker.cc::146::1: handshake_manager 0x79210acd40: calling handshaker security [0x7922005080] at index 2

LogPlayLevel: UAT: 02-23 22:51:34.794 23217 23654 D UE      : [2023.02.23-18.51.34:794][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\iomgr\tcp_posix.cc::1805::1: WRITE 0x7921e36a00 (peer=ipv4:xx.xxx.xxx.xxx:443)

LogPlayLevel: UAT: 02-23 22:51:34.794 23217 23654 D UE      : [2023.02.23-18.51.34:794][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\iomgr\tcp_posix.cc::1809::0: WRITE DATA: 16 03 01 01 3b 01 00 01 37 03 03 4e 99 e3 c7 53 58 21 9b b3 ea c8 e2 8f ac 53 59 dc d6 9c 2c 2c f8 59 96 a9 9b 45 0a 5e 5b 96 43 20 1c e0 b5 3d b9 5d 4b 26 39 94 26 50 72 2e 9c 61 78 27 df 13 50 ad eb 0e f5 dc 0f c7 ba 00 7f 60 00 10 13 02 13 03 13 01 c0 2b c0 2c c0 2f c0 30 00 ff 01 00 00 de 00 00 00 1a 00 18 00 00 15 61 70 69 2d 73 74 75 64 69 6f 2e 69 6e 77 6f 72 6c 64 2e 61 69 00 0b 00 04 03 00 01 0

2 00 0a 00 04 00 02 00 17 00 23 00 00 33 74 00 00 00 10 00 0e 00 0c 08 67 72 70 63 2d 65 78 70 02 68 32 00 16 00 00 00 17 00 00 00 0d 00 30 00 2e 04 03 05 03 06 03 08 07 08 08 08 09 08 0a 08 0b 08 04 08 05 08 06 04 01 05 01 06 01 03 03 02 03 03 01 02 01 03 02 02 02 04 02 05 02 06 02 00 2b 00 05 04 03 04 03 03 00 2d 00 02 01 01 00 33 00 47 00 45 00 17 00 41 04 cb 7e c2 38 1b 3e 7d 6e 3b 89 2c 7c 10 ff 77 8f 37 94 14 db 35 bf 05 ea 29 cc 3a b3 90 fa 85 b2 2e 2e 3c d2 ff 5c 19 96 a4

LogPlayLevel: Error: UAT: 02-23 22:51:34.806 23217 23654 D UE      : [2023.02.23-18.51.34:806][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\iomgr\tcp_posix.cc::1853::1: write: UNKNOWN:Bad address {created_time:"2023-02-23T22:51:34.794166725+04:00", errno:14, os_error:"Bad address", syscall:"sendmsg", fd:135, grpc_status:14, target_address:"ipv4:xx.xxx.xxx.xxx:443"}

LogPlayLevel: Error: UAT: 02-23 22:51:34.807 23217 23654 D UE      : [2023.02.23-18.51.34:807][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\security\transport\security_handshaker.cc::207::0: Security handshake failed: UNKNOWN:Handshake write failed {created_time:"2023-02-23T22:51:34.806897975+04:00", children:[UNKNOWN:Bad address {target_address:"ipv4:xx.xxx.xxx.xxx:443", grpc_status:14, fd:135, syscall:"sendmsg", os_error:"Bad address", errno:14, created_time:"2023-02-23T22:51:34.794166725+04:00"}]}

LogPlayLevel: Error: UAT: 02-23 22:51:34.807 23217 23654 D UE      : [2023.02.23-18.51.34:807][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\transport\handshaker.cc::100::1: handshake_manager 0x79210acd40: error=UNKNOWN:Handshake write failed {created_time:"2023-02-23T22:51:34.806897975+04:00", children:[UNKNOWN:Bad address {target_address:"ipv4:xx.xxx.xxx.xxx:443", grpc_status:14, fd:135, syscall:"sendmsg", os_error:"Bad address", errno:14, created_time:"2023-02-23T22:51:34.794166725+04:00"}]} shutdown=0 index=3, args={endpoint=(nil), args={}, read_buffer=(nil) (length=0),

exit_early=0}

LogPlayLevel: Error: UAT: 02-23 22:51:34.807 23217 23654 D UE      : [2023.02.23-18.51.34:807][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\transport\handshaker.cc::132::1: handshake_manager 0x79210acd40: handshaking complete -- scheduling on_handshake_done with error=UNKNOWN:Handshake write failed {created_time:"2023-02-23T22:51:34.806897975+04:00", children:[UNKNOWN:Bad address {target_address:"ipv4:xx.xxx.xxx.xxx:443", grpc_status:14, fd:135, syscall:"sendmsg", os_error:"Bad address", errno:14, created_time:"2023-02-23T22:51:34.794166725+04:00"}]}

LogPlayLevel: UAT: 02-23 22:51:34.807 23217 23654 D UE      : [2023.02.23-18.51.34:807][  0]Logproject: GRPC C:\Projects\project\grpc2\grpc\src\core\lib\resource_quota\memory_quota.cc::463::1: Removing allocator 0x792141afd8

четверг, 23 февраля 2023 г. в 12:34:46 UTC+4, Artem V: