[BUG]: <title>[warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]

[Brianswu]

vSomeip Version

v3.1.37.1

Boost Version

1.71

Environment

Embedded Linux

Describe the bug

using the subscribe functionm, I got this warning create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102], the client could not subscribe this event.
The application scenarios is vsomeip server offer servers, client subscribe server.
this is my servers configuration:
server_vsomeip.json
this is client configuration:
client_vsomeip.json
Why do I get this warning and how to fix this?

Reproduction Steps

No response

Expected behaviour

No response

Logs and Screenshots

No response

[duartenfonseca]

@Brianswu can you give more logs related to this error? i'm trying to reproduce it, and am not being able only with so few information

[Brianswu]

Here is the someip client log, I got the " create_eventgroup_entry: Cannot create subscription as local unreliable port is zero" error, but I have setted the port to 30494, I have no idea for this issue. Thanks for your replay @duartenfonseca
2024-08-30 08:59:33.352449 [info] Parsed vsomeip configuration in 3ms
2024-08-30 08:59:33.360380 [info] Using configuration file: "./vsomeip.json".
2024-08-30 08:59:33.363430 [info] Configuration module loaded.
2024-08-30 08:59:33.368920 [info] Initializing vsomeip application "tbox_someip_client".
2024-08-30 08:59:33.374410 [info] Instantiating routing manager [Host].
2024-08-30 08:59:33.385696 [info] create_local_server Routing endpoint at /tmp/vsomeip-0
2024-08-30 08:59:33.397286 [info] Service Discovery enabled. Trying to load module.
2024-08-30 08:59:33.420467 [info] Service Discovery module loaded.
2024-08-30 08:59:33.432362 [info] Application(tbox_someip_client, 1313) is initialized (11, 100).
2024-08-30 08:59:33.449138 [info] REGISTER EVENT(1313): [0102.0001.8004:is_provider=false]
2024-08-30 08:59:33.457983 [info] SUBSCRIBE(1313): [0102.0001.1102:ffff:1]
2024-08-30 08:59:33.488484 [info] Starting vsomeip application "tbox_someip_client" (1313) using 2 threads I/O nice 255
2024-08-30 08:59:33.511360 [info] Watchdog is disabled!
2024-08-30 08:59:33.526610 [info] io thread id from application: 1313 (tbox_someip_client) is: b6fc0010 TID: 10811
2024-08-30 08:59:33.545521 [info] vSomeIP 3.1.37.1 | (default)
2024-08-30 08:59:33.539116 [info] shutdown thread id from application: 1313 (tbox_someip_client) is: b56a43d0 TID: 10814
2024-08-30 08:59:33.557111 [info] io thread id from application: 1313 (tbox_someip_client) is: b46a23d0 TID: 10816
2024-08-30 08:59:33.558026 [info] main dispatch thread id from application: 1313 (tbox_someip_client) is: b5ea53d0 TID: 10813
2024-08-30 08:59:33.587612 [info] Network interface "eth0" state changed: up
2024-08-30 08:59:33.620553 [info] Route "239.16.100.1/32 if: eth0 gw: n/a" state changed: up
2024-08-30 08:59:33.603778 [info] REQUEST(1313): [0102.0001:1.1]
2024-08-30 08:59:33.644954 [info] Listening at /tmp/vsomeip-1313
2024-08-30 08:59:33.653189 [info] REQUEST(1313): [0103.0001:1.1]
2024-08-30 08:59:33.659900 [info] REQUEST(1313): [0101.0001:1.1]
2024-08-30 08:59:33.651359 [info] udp_server_endpoint_impl: SO_RCVBUFFORCE successful.
2024-08-30 08:59:33.669965 [info] udp_server_endpoint_impl: SO_RCVBUF is: 1703936 (1703936) local port:30490
2024-08-30 08:59:33.675150 [debug] Joining to multicast group 239.16.100.1 from 172.16.100.50
2024-08-30 08:59:33.687960 [info] udp_server_endpoint_impl: SO_RCVBUFFORCE: successful.
2024-08-30 08:59:33.693146 [info] udp_server_endpoint_impl: SO_RCVBUF is: 1703936 (1703936) local port:30490
2024-08-30 08:59:33.700771 [info] SOME/IP routing ready.
2024-08-30 08:59:36.588221 [info] configuration_impl:find_specific_port #1: service: 102 instance: 1 reliable: 0 return specific port: 30494
2024-08-30 08:59:36.602557 [info] endpoint_manager_impl::create_remote_client: 172.16.100.30:30504 reliable: 0 using local port: 30494
2024-08-30 08:59:36.615672 [info] udp_client_endpoint_impl::connect: SO_RCVBUFFORCE successful!
2024-08-30 08:59:36.625432 [info] udp_client_endpoint_impl::connect: SO_RCVBUF is: 1703936 (1703936) local port:30494 remote:172.16.100.30:30504
2024-08-30 08:59:36.587995 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]
2024-08-30 08:59:37.596387 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]
2024-08-30 08:59:37.073423 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]
2024-08-30 08:59:38.078057 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]
2024-08-30 08:59:38.599752 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]
2024-08-30 08:59:39.082385 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]
2024-08-30 08:59:40.086409 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]
2024-08-30 08:59:40.604041 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]
^C2024-08-30 08:59:40.741905 [info] UNSUBSCRIBE(1313): [0102.0001.1102.ffff]
2024-08-30 08:59:40.745260 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [0102.0001.1102]

[duartenfonseca]

i have one suggestion, try

to use the examples (https://github.com/COVESA/vsomeip/tree/master/examples), using as service the notify-sample and as client the subscribe sample. here are some simple configs that you can adapt to try and get it to work on your setup: test_configs.tar.gz

from there you can see the differences

[Brianswu]

@duartenfonseca My code is based on this sbscribe sample. Maybe there's something wrong with my configure file of client. this is my configure file:
{
"unicast": "172.16.100.50",
"netmask": "255.255.255.0",

"logging": {
    "level": "debug",
    "console": "true",
    "file": {
        "enable": "false",
        "path": "/oemdata/log/tbox_someip_client.log"
    },
    "dlt": "false"
},

"applications": [
    {
        "name": "tbox_someip_client",
        "id": "0x1313"
    }
],

"clients": [
	{
		 "service": "0x0102",
		 "instance": "0x0001",
		 "unreliable": [ 30494 ]
	}
],
"service-discovery": {
"enable" : "true",                 
    "multicast" : "239.16.100.1",   
    "port" : "30490",                  
    "protocol" : "udp",                
    "initial_delay_min" : "0",        
    "initial_delay_max" : "100",       
    "repetitions_base_delay" : "30",  
    "repetitions_max" : "3",           
    "ttl" : "5",                       
    "cyclic_offer_delay" : "1000",     
    "request_response_delay" : "500"
}

}
I have tryed to modify "unreliable": [ 30494 ] to "unreliable": "30494", the issue don't reproduce, but the unreliable port is random. How do I modify my configure file?

[duartenfonseca]

my suggestion was so that you could run it with the simplest case (notify/subscribe) if there was still problems with that, maybe it was your environment that had some issue.
can you confirm that you can run in this case?

[Brianswu]

I just tested the simplest case (notify/subscribe)，use the test_configs.tar.gz. It run OK. But if modified the vsomeip-client.json to set unreliable port as this (set "unreliable" : [ 30494 ] ): @duartenfonseca
{
"unicast" : "172.16.100.50",
"netmask" : "255.255.255.0",
"logging" :
{
"level" : "debug",
"console" : "true",
"file" : { "enable" : "true", "path" : "/var/log/vsomeip.log" },
"dlt" : "true"
},
"applications" :
[
{
"name" : "client-sample",
"id" : "0x1343"
}
],
"clients" :
[
{
"service" : "0x1234",
"instance" : "0x5678",
"unreliable" : [ 30494 ]
}
],
"routing" : "client-sample",
"service-discovery" :
{
"enable" : "true",
"multicast" : "224.244.224.245",
"port" : "30490",
"protocol" : "udp"
}
}
I got the same issue.
Here is the log:
1970-00-01 08:35:01.402323 [info] Parsed vsomeip configuration in 2ms
1970-00-01 08:35:01.413913 [info] Using configuration file: "./vsomeip.json".
1970-00-01 08:35:01.426113 [info] Configuration module loaded.
1970-00-01 08:35:01.431603 [info] Initializing vsomeip application "client-sample".
1970-00-01 08:35:01.441363 [info] Instantiating routing manager [Host].
1970-00-01 08:35:01.455088 [info] create_local_server Routing endpoint at /tmp/vsomeip-0
1970-00-01 08:35:01.468508 [info] Service Discovery enabled. Trying to load module.
1970-00-01 08:35:01.494738 [info] Service Discovery module loaded.
1970-00-01 08:35:01.510598 [info] Application(client-sample, 1343) is initialized (11, 100).
Client settings [protocol=UDP]
1970-00-01 08:35:01.522188 [info] REGISTER EVENT(1343): [1234.5678.8778:is_provider=false]
1970-00-01 08:35:01.532863 [info] SUBSCRIBE(1343): [1234.5678.4465:ffff:0]
1970-00-01 08:35:01.542928 [info] notify_one_unlocked: Notifying 1234.5678.8778 to client 1343 failed. Event payload not set!
1970-00-01 08:35:01.552077 [info] Starting vsomeip application "client-sample" (1343) using 2 threads I/O nice 255
1970-00-01 08:35:01.573732 [info] Watchdog is disabled!
1970-00-01 08:35:01.592337 [info] io thread id from application: 1343 (client-sample) is: b6fc3890 TID: 28449
1970-00-01 08:35:01.597827 [info] shutdown thread id from application: 1343 (client-sample) is: b61e53d0 TID: 28451
1970-00-01 08:35:01.630157 [info] main dispatch thread id from application: 1343 (client-sample) is: b69e63d0 TID: 28450
Service [1234.5678] is NOT available.
1970-00-01 08:35:01.635342 [info] io thread id from application: 1343 (client-sample) is: b51e33d0 TID: 28453
1970-00-01 08:35:01.625887 [info] vSomeIP 3.1.37.1 | (default)
1970-00-01 08:35:01.673467 [info] Network interface "eth0" state changed: up
1970-00-01 08:35:01.677127 [info] REQUEST(1343): [1234.5678:255.4294967295]
1970-00-01 08:35:01.702137 [info] Route "224.244.224.245/32 if: eth0 gw: n/a" state changed: up
1970-00-01 08:35:01.721657 [info] udp_server_endpoint_impl: SO_RCVBUFFORCE successful.
1970-00-01 08:35:01.712507 [info] Listening at /tmp/vsomeip-1343
1970-00-01 08:35:01.739957 [info] udp_server_endpoint_impl: SO_RCVBUF is: 1703936 (1703936) local port:30490
1970-00-01 08:35:01.750937 [debug] Joining to multicast group 224.244.224.245 from 172.16.100.50
1970-00-01 08:35:01.763442 [info] udp_server_endpoint_impl: SO_RCVBUFFORCE: successful.
1970-00-01 08:35:01.771677 [info] udp_server_endpoint_impl: SO_RCVBUF is: 1703936 (1703936) local port:30490
1970-00-01 08:35:01.784792 [info] SOME/IP routing ready.
1970-00-01 08:35:01.621861 [info] configuration_impl:find_specific_port #1: service: 1234 instance: 5678 reliable: 0 return specific port: 30494
1970-00-01 08:35:01.628876 [info] endpoint_manager_impl::create_remote_client: 172.16.100.30:30504 reliable: 0 using local port: 30494
1970-00-01 08:35:01.633451 [info] udp_client_endpoint_impl::connect: SO_RCVBUFFORCE successful!
1970-00-01 08:35:01.635891 [info] udp_client_endpoint_impl::connect: SO_RCVBUF is: 1703936 (1703936) local port:30494 remote:172.16.100.30:30504
1970-00-01 08:35:01.639551 [warning] sd::get_eventgroup_reliability: couldn't determine eventgroup reliability type for [1234.5678.4465] using reliability type: 0002
Service [1234.5678] is available.
1970-00-01 08:35:02.623691 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [1234.5678.4465]
1970-00-01 08:35:03.627961 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [1234.5678.4465]
1970-00-01 08:35:04.633451 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [1234.5678.4465]
1970-00-01 08:35:05.643821 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [1234.5678.4465]
1970-00-01 08:35:06.643821 [warning] create_eventgroup_entry: Cannot create subscription as local unreliable port is zero: [1234.5678.4465]