COVESA / vsomeip

An implementation of Scalable service-Oriented MiddlewarE over IP
Mozilla Public License 2.0
1.1k stars 684 forks source link

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

Closed Brianswu closed 1 week ago

Brianswu commented 1 month ago

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 commented 1 month ago

@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 commented 1 month ago

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 commented 1 month ago

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 commented 1 month ago

@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 commented 3 weeks ago

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 commented 3 weeks ago

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]

duartenfonseca commented 1 week ago

Hi @Brianswu I was able to reproduce your problem. This is a bug that only is present on 3.1.37.1, the version you have. Can you try and update do 3.4.10? I used the same exact configs to the latest version and it worked. Will close it since it is not a bug for the current version and we do not support vsomeip 3.1 anymore