iotivity / iotivity-lite

To contribute code to the project, please visit
https://iotivity.org/get-involved
Apache License 2.0
126 stars 67 forks source link

Question about : v2.2.4.3 verified as compliant with the CTT #321

Closed Askidea closed 2 years ago

Askidea commented 2 years ago

Hello,

I have a few questions regarding the CTT certification.

I saw that v2.2.4.3 was verified to be CTT compatible in tags description. If so, I would like to know in what test environment it was performed at the time of verification. The CTT version will be 2103.0.0, I wonder what the IUT is and what the PICS file contents are.

I am developing OCF Client in the Android app to which the iotivity library is applied, and when I test with any iotivity library version with CTT 2103, several FAIL items occur for all. Also, depending on the build options (ALL=1) or (CLOUD=0 TCP=0 others=1), the success or failure of the CTT test item may vary slightly.

To summarize the questions: 1) At the time of testing with CTT 2103, what were the IUT and PICS? 2) How did you specify the build options for the iotivity library version? 3) Have you tested it in both Linux and Android environments?

I would be grateful if someone who knows well about the above could give me some answers. I hope you know that this is very important to me and urgent.

Thanks

SiMet commented 2 years ago

Hi,

We test it only with Linux env. We use CTT from lastest code (As a Comarch we develop this tool), so it could contain some not released fixes and updates.

We use For testing we use few sample applications:

ServerCertification (TCP=1 IPV4=0 SWUPDATE=1 CREATE=1 MNT=1 CLOUD=1 DEBUG=0 V6DNS=1 WKCORE=1) PICS:

    "device": "Device_name",
    "company": "Company_name",
    "platformVersion": "1.0",
    "role": "Server",
    "icv": "ocf.2.2.5",
    "dmv": "ocf.res.1.3.0, ocf.sh.1.3.0",
    "supportedVerticalProfile": [
        "Smart Home"
    ],
    "supportedDeviceTypes": [
        "oic.d.switch"
    ],
    "resources": [
        "oic.r.sdi",
        "oic.wk.mnt",
        "oic.r.switch.binary",
        "oic.r.sp",
        "oic.wk.res",
        "oic.wk.con",
        "oic.r.csr",
        "oic.r.roles",
        "oic.r.temperature",
        "oic.wk.col",
        "oic.r.ael",
        "oic.r.coapcloudconf",
        "oic.r.softwareupdate",
        "oic.r.dali",
        "oic.r.dali.conf",
        "oic.r.remotecontrol"
    ],
    "optionalFeatures": [
        "batchInterface",
        "supportsWellknownCoreDiscovery"
    ],
    "OTM": [
        "oic.sec.doxm.jw",
        "oic.sec.doxm.rdp",
        "oic.sec.doxm.mfgcert"
    ],
    "contentFormatVersion": [
        "1.0.0"
    ],
    "acceptVersion": [
        "1.0.0"
    ],
    "supportedSecurityProfiles": [
        "sp-baseline-v0",
        "sp-black-v0",
        "sp-blue-v0",
        "sp-purple-v0"
    ],
    "cplAtIANAPen": "1.3.6.1.4.1.71",
    "cplAtModel": "Discovery",
    "cplAtVersion": "1.0",
    "observableOICRES": false,
    "sct": 457,
    "persistentDeviceuuid": false,
    "RDPublishCapability": true,
    "SSIDSoftAP": "",
    "PasswordSoftAP": "",
    "canTurnOnSoftApManually": true,
    "jurisdictionSwitch": false,
    "minNotifyPeriod": [
        0,
        10000
    ],
    "maxNotifyPeriod": [
        0,
        20000
    ],
    "threshold": [
        0,
        5
    ],
    "threshold_recommended_value": 2,
    "multiValueQuerySupport": true,
    "atomicMeasurements": [

    ],
    "supportsCoAPoverTCP": true,
    "OIC11Support": false,
    "supportsMultipleDTLS": true
}

OnboardingTool (TCP=1 IPV4=0 SWUPDATE=1 CREATE=1 MNT=1 CLOUD=1 DEBUG=0) PICS:

{
    "device": "OBT",
    "company": "Intel Corporation",
    "platformVersion": "1.0",
    "role": "Client",
    "icv": "ocf.2.2.5",
    "dmv": "ocf.res.1.3.0",
    "supportedVerticalProfile": [
        "Smart Home"
    ],
    "supportedDeviceTypes": [
        "oic.d.dots",
        "oic.d.cms",
        "oic.d.ams",
        "oic.wk.d",
        "oic.d.airpurifier"
    ],
    "resources": [
        "oic.r.csr",
        "oic.r.roles",
        "oic.r.sp",
        "oic.wk.mnt",
        "oic.d.dots",
        "oic.d.cms",
        "oic.d.ams",
        "oic.r.softwareupdate"
    ],
    "optionalFeatures": [

    ],
    "OTM": [
        "oic.sec.doxm.jw",
        "oic.sec.doxm.rdp",
        "oic.sec.doxm.mfgcert"
    ],
    "contentFormatVersion": [
        "1.0.0"
    ],
    "acceptVersion": [
        "1.0.0"
    ],
    "supportedSecurityProfiles": [
        "sp-baseline-v0",
        "sp-black-v0",
        "sp-blue-v0",
        "sp-purple-v0"
    ],
    "cplAtIANAPen": "1.3.6.1.4.1.71",
    "cplAtModel": "Discovery",
    "cplAtVersion": "1.0",
    "multiValueQuerySupport": false,
    "sct": 1,
    "supportsCoAPoverTCP": true,
    "canTurnOnSoftAPManually": false,
    "observableOICRES": false,
    "supportsCancellingObserve": false,
    "persistentDeviceuuid": false,
    "onboardingRoles": [
        "ams",
        "cms",
        "dots"
    ],
    "onboardingOTM": [
        "oic.sec.doxm.jw",
        "oic.sec.doxm.rdp",
        "oic.sec.doxm.mfgcert"
    ],
    "onboardingSpec": [
        "ocf.1.3"
    ]
}

ClientCertification (TCP=1 IPV4=0 SWUPDATE=1 CREATE=1 MNT=1 DEBUG=0 V6DNS=1 WKCORE=1) PICS:

{
    "device": "Client",
    "company": "Company_name",
    "platformVersion": "1.0",
    "role": "Client",
    "icv": "ocf.2.2.5",
    "dmv": "ocf.res.1.3.0, ocf.sh.1.3.0",
    "supportedVerticalProfile": [
        "Smart Home"
    ],
    "supportedDeviceTypes": [
        "oic.d.light"
    ],
    "resources": [
        "oic.r.sdi",
        "oic.wk.res",
        "oic.r.csr",
        "oic.r.ael",
        "oic.r.sp",
        "oic.r.roles",
        "oic.wk.mnt",
        "oic.wk.con",
        "oic.r.softwareupdate"
    ],
    "optionalFeatures": [
        "batchInterface",
        "ipv6Scope3",
        "ipv6Scope5",
        "supportsWellknownCoreDiscovery"
    ],
    "OTM": [
        "oic.sec.doxm.jw",
        "oic.sec.doxm.rdp",
        "oic.sec.doxm.mfgcert"
    ],
    "contentFormatVersion": [
        "1.0.0"
    ],
    "acceptVersion": [
        "1.0.0"
    ],
    "supportedSecurityProfiles": [
        "sp-baseline-v0",
        "sp-black-v0",
        "sp-blue-v0",
        "sp-purple-v0"
    ],
    "cplAtIANAPen": "1.3.6.1.4.1.71",
    "cplAtModel": "Discovery",
    "cplAtVersion": "1.0",
    "multiValueQuerySupport": false,
    "sct": 457,
    "supportsCoAPoverTCP": true,
    "canTurnOnSoftApManually": false,
    "observableOICRES": true,
    "supportsCancellingObserve": true,
    "persistentDeviceuuid": false,
    "onboardingRoles": [

    ],
    "onboardingOTM": [

    ],
    "onboardingSpec": [

    ],
    "PasswordSoftAP": null,
    "RDPublishCapability": false,
    "SSIDSoftAP": null,
    "atomicMeasurements": [

    ],
    "authorizationServerUrl": null,
    "cis": null,
    "cloudAccountPassword": null,
    "cloudAccountUrl": null,
    "cloudAccountUser": null,
    "cloudClientCertificate": null,
    "cloudClientPrivateKey": null,
    "cloudServerTrustAnchorCertificate": null,
    "deviceApiUrl": null,
    "jurisdictionSwitch": false,
    "maxNotifyPeriod": [

    ],
    "minNotifyPeriod": [

    ],
    "redirectUri": null,
    "sid": null,
    "threshold": [

    ],
    "threshold_recommended_value": 0,
    "validClientId": null,
    "validClientSecret": null,
    "supportsMultipleDTLS": true
}
Askidea commented 2 years ago

@SiMet Thanks for your kind reply.

In Android, I'm testing my OCF Client app with v2.2.4.3 or master branch and CTT 2103.0.0.

May I ask for some advice on how to test the next item of CTT?

(1) CT1.2.6 RETRIEVE Message with observe indication based on CoAP - NOTIFY Prompt: Please change some value in /oic/p resource and press OK Prompt: Please change some value in /oic/d resource and press OK =====> I tried update /oic/p > mnmn or /oic/d name locally inside client app, but access denied. How can I change /oic/p and /oic/d as prompted?

(2) CT2.2.7 RETRIEVE Message with observe indication based on CoAP over TCP - NOTIFY Prompt: Please have the IUT establish a TCP connection with the CTT. ======> I cannot find a CTT host address. Where can I find CTT address?

If these items are resolved, it is likely that v2.2.4.3 will be verified in the Android environment. I look forward to your help. Thank you in advance.

My PICS:

{ "device": "Device", "company": "Askidea", "cplAtIANAPen": "", "platformVersion": "1.0.0", "cplAtVersion": "1.0.0", "cplAtModel": "M140", "role": "Client", "supportedVerticalProfile": [ "Smart Home" ], "supportedDeviceTypes": [ "oic.d.switch", "oic.d.light", "oic.d.smartlock" ], "icv": "ocf.2.2.4", "dmv": "ocf.res.1.3.0", "acceptVersion": [ "1.0.0" ], "resources": [ "oic.r.csr", "oic.r.roles", "oic.r.sdi", "oic.r.sp", "oic.r.coapcloudconf" ], "optionalFeatures": [], "OTM": [ "oic.sec.doxm.jw" ], "contentFormatVersion": [ "1.0.0" ], "multiValueQuerySupport": false, "supportsMultipleDTLS": false, "cloudRegisterAutoRetry": false, "sct": 9, "supportsCoAPoverTCP": true, "canTurnOnSoftAPManually": false, "observableOICRES": false, "supportsCancellingObserve": false, "persistentDeviceuuid": false, "supportedSecurityProfiles": [ "sp-baseline-v0" ], "supportseSIMEasySetup": false }

SiMet commented 2 years ago

@Askidea

1) CT1.2.6 in our test app we set /oic/p and /oic/d as not observable. Does your device require to have /oic/d /oic/p resources observable?

2) In test CT2.2.7 CTT starts simulator which you should be able to discover. In discovery response there are endpoints for each resource. You need to look for endpoint which starts with "coap+tcp" or "coaps+tcp" and perform Retrieve operation on such resource.

Askidea commented 2 years ago

@SiMet

(1) CT1.2.6 Regarding Linux, there is the method to set resources(/oic/p, /oic/d, etc) obsersable or unobserable by getting the resource by index. But, for Android, probably there is no any java binding method to get resource object about /oic/p or /oic/d.

[Example: server_certification_tests.c] oc_resource_t *device_resource = oc_core_get_resource_by_index(OCF_D, DEVICE);
oc_resource_set_observable(device_resource, false); observable);

oc_resource_t *platform_resource = oc_core_get_resource_by_index(OCF_P, DEVICE); oc_resource_set_observable(platform_resource, false);

(2) CT2.2.7 Using the 'client_certification_tests' binary in Linux, it was successful to make a TCP connection by performing a GET(coaps+tcp) request for a resource. However, an OC_STATUS_SERVICE_UNAVAILABLE error occurs when a GET request is performed in an Android app. The resource endpoint of the CTT device simulator seems to have been specified correctly. I'm still checking on this issue.

SiMet commented 2 years ago

I'm not expert in JNI and Swig but there is probably method in Java OCCoreRes.getResourceByIndex which is bound to oc_core_get_resource_by_index.

Please see: https://github.com/iotivity/iotivity-lite/blob/master/swig/swig_interfaces/oc_core_res.i

Askidea commented 2 years ago

@SiMet

Thanks for your advice. I modified the code based on your advice, and CT1.2.6 passed. For your information, I used a more intuitive OCCoreRes.getResourceByUri() instead of getResourceByIndex(). Finding resources with indexes was not easy.

Askidea commented 2 years ago

@SiMet Regarding CT2.2.7, there seems to be some difference between the Linux library and the Android library. When I analyzed the log, there was a difference in the ciphersuite setting. It seems that both the client and server libraries are included in the Android library, but in the actual log, the client function code does not seem to be applied. It seems that #ifdef OC_CLIENT is not properly reflected in the oc_tls_set_ciphersuites() function in the oc_tls.c file. I don't know if this is accurate analysis because code analysis is not easy for me.

For reference, I attach 'client_certification_tests' and my OCfClient-side log in the process of performing TCP GET on the resource.

D: oc_oscore_engine.c : Posting INIT_TLS_CONN_EVENT D: oc_oscore_engine.c : Outbound OSCORE event: protecting message D: oc_oscore_engine.c : ################################# D: oc_oscore_engine.c : Outbound network event: forwarding to TLS D: oc_oscore_engine.c : Posting INIT_TLS_CONN_EVENT D: oc_pstat.c : oc_pstat: dos is RFNOP D: oc_pstat.c : oc_pstat: dos is RFNOP D: oc_tls.c : oc_tls: Allocating new peer D: oc_pstat.c : oc_pstat: dos is RFNOP D: oc_pstat.c : oc_pstat: dos is RFNOP D: oc_tls.c : loading identity cert chain W: oc_tls.c : error configuring identity cert D: oc_tls.c : loading manufacturer cert chain D: oc_pstat.c : oc_pstat: dos is RFNOP D: oc_tls.c : oc_tls_set_ciphersuites: server selecting default ciphersuite priority D: oc_tls.c : oc_tls_set_ciphersuites: client selecting PSK ciphersuite priority D: oc_tls.c : oc_tls: resetting ciphersuite selection for next handshakes mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:8130: => handshake mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:3581: client state: 0 mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:2762: => flush output mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:2774: <= flush output mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:3581: client state: 1 mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:2762: => flush output mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:2774: <= flush output mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0781: => write client hello mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0818: client hello, max version: [3:3] mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0710: client hello, current time: 1664516417 mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0828: dumping 'client hello, random bytes' (32 bytes) mbedtls_log: ../../deps/mbedtls/library/sslcli.c:0828: 0000: 63 36 81 41 20 0e 4c 9c b6 5f 0c 17 31 4b b4 26 c6.A .L....1K.& mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0828: 0010: f2 0b f3 db 68 02 5a 30 f1 a6 68 81 84 3c 44 07 ....h.Z0..h..<D. mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0881: client hello, session id len.: 0 mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0882: dumping 'client hello, session id' (0 bytes) mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0928: client hello, add ciphersuite: c037 mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0941: client hello, got 1 ciphersuites (excluding SCSVs) mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0950: adding EMPTY_RENEGOTIATION_INFO_SCSV mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0999: client hello, compress len.: 1 mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:1000: client hello, compress alg.: 0 mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0186: client hello, adding signature_algorithms extension mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0271: client hello, adding supported_elliptic_curves extension mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0336: client hello, adding supported_point_formats extension mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:0558: client hello, adding extended_master_secret extension mbedtls_log: ../../deps/mbedtls/library/ssl_cli.c:1077: client hello, total extension length: 32 mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:3197: => write handshake message mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:3356: => write record mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:3433: output record: msgtype = 22, version = [3:3], msglen = 81 mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:3438: dumping 'output record sent to network' (86 bytes) mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:3438: 0000: 16 03 03 00 51 01 00 00 4d 03 03 63 36 81 41 20 ....Q...M..c6.A mbedtls_log: ../../deps/mbedtls/library/ssltls.c:3438: 0010: 0e 4c 9c b6 5f 0c 17 31 4b b4 26 f2 0b f3 db 68 .L....1K.&....h mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:3438: 0020: 02 5a 30 f1 a6 68 81 84 3c 44 07 00 00 04 c0 37 .Z0..h..<D.....7 mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:3438: 0030: 00 ff 01 00 00 20 00 0d 00 0a 00 08 04 03 04 01 ..... .......... mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:3438: 0040: 03 03 03 01 00 0a 00 04 00 02 00 17 00 0b 00 02 ................ mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:3438: 0050: 01 00 00 17 00 00 ...... mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:2762: => flush output mbedtls_log: ../../deps/mbedtls/library/ssl_tls.c:2780: message length: 86, out_left: 86 Outgoing message of size 86 bytes to coaps+tcp://[fe80:0000:0000:0000:2c3d:ce34:1b17:3760]:49202

could not find ongoing TCP session for endpoint:coaps+tcp://[fe80:0000:0000:0000:2c3d:ce34:1b17:3760]:49202 D: tcpadapter.c : successfully initiated TCP connection ####### SUCCESS!!!!!!!!!!!! D: tcpadapter.c : recorded new TCP session D: tcpadapter.c : signaled network event thread to monitor the newly added session found TCP session for endpoint:coaps+tcp://[fe80:0000:0000:0000:2c3d:ce34:1b17:3760]:49202

SiMet commented 2 years ago

I'm not familiar with Android implementation. Maybe @Danielius1922 could help us or point someone who could help us.

Askidea commented 2 years ago

@SiMet, @Danielius1922 For CT2.2.7, after changing to IPv4/Secure/TCP, the TCP connection was successful and the CT item was passed. But for IPv6, the TCP connection failed as I said above. Why is IPv6 TCP connection working on Linux and not on Android? Could it be a problem with the mbedtls library? For now, this is what I've checked.

image

Danielius1922 commented 2 years ago

@Askidea: I am sorry, I didn't notice this. I'm not really familiar with Android implementation either, however as far as I'm aware it's almost identical to the Linux v2.2.5.1 port.

Your log analysis seems to be on the right track, however I think the OC_CLIENT ifdef is working because the log

Posting INIT_TLS_CONN_EVENT

is always under OC_CLIENT ifdef, and that log occurs in both of the log traces you posted, so that makes me think it is in order. So I think what is failing is this:

      oc_sec_cred_t *cred =
        oc_sec_find_creds_for_subject(&endpoint->di, NULL, endpoint->device);
      if (cred && cred->credtype == OC_CREDTYPE_PSK) {

It cannot find the PSK certificate. If you look in the log trace of the failing case there is this:

I/../../security/oc_tls.c <oc_tls_load_mfg_cert_chain:1229>: loading manufacturer cert chain
I/../../security/oc_tls.c <oc_tls_configure_end_entity_cert_chain:1219>: error configuring identity cert

Whilst in the successful case the loading of the manufacturer cert chain succeeds. We need to find out why the loading of manufacturer cert chain is failing. Could you please attach the full My OCF Client's Log? Maybe there are some other errors preceding the ones you've posted.

Askidea commented 2 years ago

@Danielius1922

For IPv4, also following lines appeared. But TCP connection initiated successfully (CT 2.2.7). I/../../security/oc_tls.c <oc_tls_load_identity_cert_chain:1238>: loading identity cert chain I/../../security/oc_tls.c <oc_tls_configure_end_entity_cert_chain:1219>: error configuring identity cert I/../../security/oc_tls.c <oc_tls_load_mfg_cert_chain:1229>: loading manufacturer cert chain I/../../security/oc_tls.c <oc_tls_configure_end_entity_cert_chain:1219>: error configuring identity cert

Please refer to log files belows. Look for "Comment by Askidea" for convience.

CTT2103_CT2.2.7_master_29ccbf39_IPv4_OCFClient logcat_20221012.txt

CTT2103_CT2.2.7_master_29ccbf39_IPv6_OCFClient logcat_20221012.txt

CTT2103_CT2.2.7_master_29ccbf39_IPv6_CTT log_20221012.txt

Danielius1922 commented 2 years ago

@Askidea

Indeed those errors are also in the IPV4 trace, so they most likely aren't relevant to the problem. What is definitely an issue is this:

2022-10-12 11:44:31.412 11322-11368 I/OC-JNI: could not find ongoing TCP session for endpoint:
2022-10-12 11:44:31.412 11322-11368 I/OC-JNI: coaps+tcp://[fe80:0000:0000:0000:2c3d:ce34:1b17:3760]:49190
2022-10-12 11:44:31.412 11322-11368 I/OC-JNI: 
2022-10-12 11:44:31.417 11322-11368 I/tcpadapter.c <initiate_new_session:565>: connect fail with -1. retry(1)
2022-10-12 11:44:31.419 11322-11368 I/tcpadapter.c <initiate_new_session:565>: connect fail with -1. retry(2)
2022-10-12 11:44:31.422 11322-11368 I/tcpadapter.c <initiate_new_session:565>: connect fail with -1. retry(3)
2022-10-12 11:44:31.425 11322-11368 I/tcpadapter.c <initiate_new_session:565>: connect fail with -1. retry(4)
2022-10-12 11:44:31.427 11322-11368 I/tcpadapter.c <initiate_new_session:565>: connect fail with -1. retry(5)
2022-10-12 11:44:31.428 11322-11368 I/tcpadapter.c <initiate_new_session:569>: could not initiate TCP connection
2022-10-12 11:44:31.428 11322-11368 I/tcpadapter.c <oc_tcp_send_buffer:609>: could not initiate new TCP session

In the IPV4 logs the TCP connection is established. We don't print the errno sadly, so we don't get the exact reason why connect fails here. The IPV6 address is one of the CTT client endpoints:

11:43:04 DEBUG Simulator CTT Light Simulator started at: [fe80::2c3d:ce34:1b17:3760%19]:49187 [fe80::2c3d:ce34:1b17:3760%19]:49189 [fe80::2c3d:ce34:1b17:3760%19]:49188 [fe80::2c3d:ce34:1b17:3760%19]:49190

Maybe the endpoint at [fe80::2c3d:ce34:1b17:3760%19]:49190 wasn't started properly or its not reachable for some reason. The only idea I currently have is to add errno to the logs, so we know why exactly it failed.

Danielius1922 commented 2 years ago

@Askidea can you please retry with the branch from this PR - https://github.com/iotivity/iotivity-lite/pull/327 ? I've added some logs, lets see if they tell us something.

Askidea commented 2 years ago

@Danielius1922

Here are the log files.

OCFClient_log_android-tcp-logs_20221014.txt

CTT_log_android-tcp-logs_20221014.txt

And there are compile errors in the branch 'android-tcp-logs' because of a typo, e.g. "ernno".

Danielius1922 commented 2 years ago

@Askidea

Sorry about that, I've added the logs but compiled the code without enabling debug logs. I've fixed it in the branch.

You've figured it out anyway, so looking at the logs:

2022-10-14 13:02:16.641 29917-29945 I/OC-JNI: Outgoing message of size 110 bytes to 
2022-10-14 13:02:16.641 29917-29945 I/OC-JNI: coaps+tcp://[fe80:0000:0000:0000:2c3d:ce34:1b17:3760]:49176
2022-10-14 13:02:16.641 29917-29945 I/OC-JNI: 
2022-10-14 13:02:16.641 29917-29945 I/OC-JNI: could not find ongoing TCP session for endpoint:
2022-10-14 13:02:16.641 29917-29945 I/OC-JNI: coaps+tcp://[fe80:0000:0000:0000:2c3d:ce34:1b17:3760]:49176
2022-10-14 13:02:16.641 29917-29945 I/OC-JNI: 
2022-10-14 13:02:16.645 29917-29945 I/tcpadapter.c <connect_nonb:494>: failed to connect to address (error=22)
2022-10-14 13:02:16.645 29917-29945 I/tcpadapter.c <initiate_new_session:567>: connect failed, retry(1)
2022-10-14 13:02:16.651 29917-29945 I/tcpadapter.c <connect_nonb:494>: failed to connect to address (error=22)
2022-10-14 13:02:16.651 29917-29945 I/tcpadapter.c <initiate_new_session:567>: connect failed, retry(2)
2022-10-14 13:02:16.655 29917-29945 I/tcpadapter.c <connect_nonb:494>: failed to connect to address (error=22)
2022-10-14 13:02:16.655 29917-29945 I/tcpadapter.c <initiate_new_session:567>: connect failed, retry(3)
2022-10-14 13:02:16.658 29917-29945 I/tcpadapter.c <connect_nonb:494>: failed to connect to address (error=22)
2022-10-14 13:02:16.658 29917-29945 I/tcpadapter.c <initiate_new_session:567>: connect failed, retry(4)
2022-10-14 13:02:16.660 29917-29945 I/tcpadapter.c <connect_nonb:494>: failed to connect to address (error=22)
2022-10-14 13:02:16.660 29917-29945 I/tcpadapter.c <initiate_new_session:567>: connect failed, retry(5)
2022-10-14 13:02:16.660 29917-29945 I/tcpadapter.c <initiate_new_session:571>: could not initiate TCP connection
2022-10-14 13:02:16.660 29917-29945 I/tcpadapter.c <oc_tcp_send_buffer:611>: could not initiate new TCP session

Error 22 is EINVAL = invalid input. The failing call looks like this:

if ((n = connect(sockfd, (struct sockaddr *)r, r_len)) < 0) {

sockfd must be valid, because the fcntl calls preceding the connect call succeed. The problematic value must be then the r value with the socket address. The address used (fe80::2c3d:ce34:1b17:3760) is a link-local address and as I understand it for link-local addresses sin6_scope_id must be set to >0 value. Unfortunately, the logging functions ignore the scope_id value, so we don't know whether the value was set or not, but given the fact that we get EINVAL error it must not be set.

Now it's possible that the scope_id value gets zeroed somewhere or it was perhaps never set?

At the beginning of the logs I see the following lines

2022-10-14 13:02:16.628 29917-29917 E/OCFClientService: (OCF-Client -----------------------------------------------------> MPBridge)
2022-10-14 13:02:16.631 29917-29917 I/EpUtil: ep[0] = coaps://[fe80::2c3d:ce34:1b17:3760]:49175
2022-10-14 13:02:16.631 29917-29917 I/EpUtil: ep[1] = coaps+tcp://[fe80::2c3d:ce34:1b17:3760]:49176
2022-10-14 13:02:16.632 29917-29917 I/iotivity-lite-java/jni/oc_endpoint_wrap.c <jni_string_to_endpoint_a:310>: JNI: jni_string_to_endpoint_a
2022-10-14 13:02:16.634 29917-29917 E/OCFClientService: doGet() : dt=oic.d.light, uri=/BinarySwitchResURI, query=[rt=oic.r.switch.binary],  coaps+tcp://[fe80::2c3d:ce34:1b17:3760]:49176

I see two link-local addresses there, but no scope_id, though I don't know if the logging functions just ignore it or it is indeed not set. What are you using to print the addresses? And where do the addresses come from, some sort of configuration? If it is a configuration somewhere, then maybe it is missing the scope_id value in the address...?

Askidea commented 2 years ago

@Danielius1922 I found the cause of the problem from your advice. The cause was that the OCEndpoint object was converted to an endpoint string, and this endpoint string was converted back to an OCEndpoint object.

OCEndpoint object --------- OCEndpointUtil.toString(OCEndpoint ep) ----------> endpoint string (e.g. coaps+tcp://[fe80::2c3d:ce34:1b17:3760]:49176) 
---------- OCEndpointUtil.stringToEndpoint(String epString) ----------> new OCEndpoint object

I think the scopo_idinformation you mentioned was lost in the process of converting the endpoint string into an OCEndpoint object.

In conclusion, CT2.2.7 passed well in IPv6/Secure/TCP. As such, this issue seems to be closed, and I am very grateful for your hard work and response.

Danielius1922 commented 2 years ago

Great to know! Glad I was able to help. :-)

(Before closing this issue I'll first investigate if the conversion from endpoint to string and back preserves the scope_id. I think that would constitute a bug.)

Danielius1922 commented 2 years ago

Indeed when converting from a string the scope_id value is not filled (and also the parsing function oc_string_to_endpoint will be stuck in an infinite loop when an ipv6 address with scope id is used as an input). I've created an enhancement to fix it - https://github.com/iotivity/iotivity-lite/issues/331 .