search

fdo-rs / fido-device-onboard-rs

An implementation of the FIDO Device Onboard (FDO) spec written in Rust.
BSD 3-Clause "New" or "Revised" License
62 stars 34 forks source link

FDO client T01 Error log #546

Closed henrywang closed 1 year ago

henrywang commented 1 year ago

When I run FDO server or aio tests, 80% of times I can get T01 error. This error doesn't block fdo functions I tested.

For fdo services:

Aug 24 03:46:23 vm-3 systemd[1]: Starting FDO client...
    Aug 24 03:46:23 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:46:23.393Z INFO  fdo_client_linuxapp > Found device credential at FileSystemPath { path: "/boot/device-credentials", deactivation_method: None }
    Aug 24 03:46:23 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:46:23.512Z ERROR fdo_client_linuxapp > Error performing TO1 with ServiceClient { protocol_version: Version1_1, base_url: "http://192.168.100.1:8082", client: Client { accepts: Accepts, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*"} }, authorization_token: None, encryption_keys: EncryptionKeys { cipher_suite: None, keys: None }, last_message_type: Some(Error), non_interoperable_kdf_required: Some(false) }
    Aug 24 03:46:23 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:46:23.513Z ERROR fdo_client_linuxapp > Error Couldn't get TO1 from any Rendezvous server! getting usable To1d from rv_entry RendezvousInterpretedDirective { ip_addresses: Some([IPAddress(192.168.100.1)]), dns_name: None, port: 8082, server_certificate_hash: None, ca_certificate_hash: None, user_input: false, wifi_ssid: None, wifi_password: None, medium: None, protocol: Http, delay: 0, bypass: false }
    Aug 24 03:48:23 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:23.544Z INFO  fdo_client_linuxapp > Got TO2 addresses: ["http://192.168.100.1:8081"]
    Aug 24 03:48:23 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:23.545Z INFO  fdo_client_linuxapp > Performing TO2 protocol, URL: "http://192.168.100.1:8081"
    Aug 24 03:48:23 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:23.600Z INFO  fdo_client_linuxapp::serviceinfo > Username is: fdouser
    Aug 24 03:48:23 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:23.601Z INFO  fdo_client_linuxapp::serviceinfo > Keys are present
    Aug 24 03:48:23 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:23.601Z INFO  fdo_client_linuxapp::serviceinfo > Creating file "/etc/sudoers.d/fdouser" with 32 bytes (mode 384)
    Aug 24 03:48:23 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:23.605Z INFO  fdo_client_linuxapp::serviceinfo > Initiating disk re-encryption, disk-label: /dev/vda4, pin: tpm2, config: {}, reencrypt: true
    Aug 24 03:48:24 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:24.426Z INFO  fdo_client_linuxapp::serviceinfo > SSHkey module was active, installing SSH keys
    Aug 24 03:48:24 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:24.427Z INFO  fdo_client_linuxapp::serviceinfo > Creating user: fdouser
    Aug 24 03:48:24 vm-3 useradd[1933]: new group: name=fdouser, GID=1001
    Aug 24 03:48:24 vm-3 useradd[1933]: new user: name=fdouser, UID=1001, GID=1001, home=/var/home/fdouser, shell=/bin/bash, from=none
    Aug 24 03:48:24 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:24.549Z INFO  fdo_client_linuxapp::serviceinfo > User fdouser created successfully
    Aug 24 03:48:24 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:24.550Z INFO  fdo_client_linuxapp::serviceinfo > Installed sshkey: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCzxo5dEcS+LDK/OFAfHo6740EyoDM8aYaCkBala0FnWfMMTOq7PQe04ahB0eFLS3IlQtK5bpgzxBdFGVqF6uT5z4hhaPjQec0G3+BD5Pxo6V+SxShKZo+ZNGU3HVrF9p2V7QH0YFQj5B8F6AicA3fYh2BVUFECTPuMpy5A52ufWu0r4xOFmbU7SIhRQRAQz2u4yjXqBsrpYptAvyzzoN4gjUhNnwOHSPsvFpWoBFkWmqn0ytgHg3Vv9DlHW+45P02QH1UFedXR2MqLnwRI30qqtaOkVS+9rE/dhnR+XPpHHG+hv2TgMDAuQ3IK7Ab5m/yCbN73cxFifH4LST0vVG3Jx45xn+GTeHHhfkAfBSCtya6191jixbqyovpRunCBKexI5cfRPtWOitM3m7Mq26r7LpobMM+oOLUm4p0KKNIthWcmK9tYwXWSuGGfUQ+Y8gt7E0G06ZGbCPHOrxJ8lYQqXsif04piONPA/c9Hq43O99KPNGShONCS9oPFdOLRT3U= ostree-image-test
    Aug 24 03:48:24 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:24.553Z INFO  fdo_client_linuxapp              > Secure Device Onboarding DONE
    Aug 24 03:48:24 vm-3 fdo-client-linuxapp[1261]:  2023-08-24T07:48:24.553Z INFO  fdo_client_linuxapp              > Reboot required? false
    Aug 24 03:48:24 vm-3 systemd[1]: fdo-client-linuxapp.service: Deactivated successfully.
    Aug 24 03:48:24 vm-3 systemd[1]: Finished FDO client.

For fdo-aio:

Aug 24 06:00:20 vm-3 systemd[1]: Starting FDO client...
    Aug 24 06:00:20 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:00:20.214Z INFO  fdo_client_linuxapp > Found device credential at FileSystemPath { path: "/boot/device-credentials", deactivation_method: None }
    Aug 24 06:00:20 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:00:20.308Z ERROR fdo_client_linuxapp > Error performing TO1 with ServiceClient { protocol_version: Version1_1, base_url: "http://10.0.192.104:8082", client: Client { accepts: Accepts, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*"} }, authorization_token: None, encryption_keys: EncryptionKeys { cipher_suite: None, keys: None }, last_message_type: Some(Error), non_interoperable_kdf_required: Some(false) }
    Aug 24 06:00:20 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:00:20.309Z ERROR fdo_client_linuxapp > Error Couldn't get TO1 from any Rendezvous server! getting usable To1d from rv_entry RendezvousInterpretedDirective { ip_addresses: Some([IPAddress(10.0.192.104)]), dns_name: None, port: 8082, server_certificate_hash: None, ca_certificate_hash: None, user_input: false, wifi_ssid: None, wifi_password: None, medium: None, protocol: Http, delay: 0, bypass: false }
    Aug 24 06:00:20 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:00:20.359Z ERROR fdo_client_linuxapp > Error performing TO1 with ServiceClient { protocol_version: Version1_1, base_url: "http://192.168.100.1:8082", client: Client { accepts: Accepts, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*"} }, authorization_token: None, encryption_keys: EncryptionKeys { cipher_suite: None, keys: None }, last_message_type: Some(Error), non_interoperable_kdf_required: Some(false) }
    Aug 24 06:00:20 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:00:20.369Z ERROR fdo_client_linuxapp > Error Couldn't get TO1 from any Rendezvous server! getting usable To1d from rv_entry RendezvousInterpretedDirective { ip_addresses: Some([IPAddress(192.168.100.1)]), dns_name: None, port: 8082, server_certificate_hash: None, ca_certificate_hash: None, user_input: false, wifi_ssid: None, wifi_password: None, medium: None, protocol: Http, delay: 0, bypass: false }
    Aug 24 06:00:20 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:00:20.397Z ERROR fdo_client_linuxapp > Error performing TO1 with ServiceClient { protocol_version: Version1_1, base_url: "http://2620:52:0:c0:f816:3eff:fe1b:4734:8082", client: Client { accepts: Accepts, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*"} }, authorization_token: None, encryption_keys: EncryptionKeys { cipher_suite: None, keys: None }, last_message_type: Some(Error), non_interoperable_kdf_required: None }
    Aug 24 06:00:20 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:00:20.397Z ERROR fdo_client_linuxapp > Error Couldn't get TO1 from any Rendezvous server! getting usable To1d from rv_entry RendezvousInterpretedDirective { ip_addresses: Some([IPAddress(2620:52:0:c0:f816:3eff:fe1b:4734)]), dns_name: None, port: 8082, server_certificate_hash: None, ca_certificate_hash: None, user_input: false, wifi_ssid: None, wifi_password: None, medium: None, protocol: Http, delay: 0, bypass: false }
    Aug 24 06:00:20 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:00:20.437Z ERROR fdo_client_linuxapp > Error performing TO1 with ServiceClient { protocol_version: Version1_1, base_url: "http://fe80::f816:3eff:fe1b:4734:8082", client: Client { accepts: Accepts, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*"} }, authorization_token: None, encryption_keys: EncryptionKeys { cipher_suite: None, keys: None }, last_message_type: Some(Error), non_interoperable_kdf_required: None }
    Aug 24 06:00:20 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:00:20.439Z ERROR fdo_client_linuxapp > Error Couldn't get TO1 from any Rendezvous server! getting usable To1d from rv_entry RendezvousInterpretedDirective { ip_addresses: Some([IPAddress(fe80::f816:3eff:fe1b:4734)]), dns_name: None, port: 8082, server_certificate_hash: None, ca_certificate_hash: None, user_input: false, wifi_ssid: None, wifi_password: None, medium: None, protocol: Http, delay: 0, bypass: false }
    Aug 24 06:02:31 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:31.471Z INFO  fdo_client_linuxapp > Got TO2 addresses: ["http://10.0.192.104:8081", "http://192.168.100.1:8081", "http://2620:52:0:c0:f816:3eff:fe1b:4734:8081", "http://fe80::f816:3eff:fe1b:4734:8081"]
    Aug 24 06:02:31 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:31.472Z INFO  fdo_client_linuxapp > Performing TO2 protocol, URL: "http://10.0.192.104:8081"
    Aug 24 06:02:31 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:31.532Z INFO  fdo_client_linuxapp::serviceinfo > Username is: fdouser
    Aug 24 06:02:31 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:31.532Z INFO  fdo_client_linuxapp::serviceinfo > Keys are present
    Aug 24 06:02:31 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:31.532Z INFO  fdo_client_linuxapp::serviceinfo > Creating file "/etc/sudoers.d/fdouser" with 32 bytes (mode 384)
    Aug 24 06:02:31 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:31.537Z INFO  fdo_client_linuxapp::serviceinfo > Initiating disk re-encryption, disk-label: /dev/vda4, pin: tpm2, config: {}, reencrypt: true
    Aug 24 06:02:32 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:32.321Z INFO  fdo_client_linuxapp::serviceinfo > SSHkey module was active, installing SSH keys
    Aug 24 06:02:32 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:32.326Z INFO  fdo_client_linuxapp::serviceinfo > Creating user: fdouser
    Aug 24 06:02:32 vm-3 useradd[1935]: new group: name=fdouser, GID=1001
    Aug 24 06:02:32 vm-3 useradd[1935]: new user: name=fdouser, UID=1001, GID=1001, home=/var/home/fdouser, shell=/bin/bash, from=none
    Aug 24 06:02:32 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:32.441Z INFO  fdo_client_linuxapp::serviceinfo > User fdouser created successfully
    Aug 24 06:02:32 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:32.442Z INFO  fdo_client_linuxapp::serviceinfo > Installed sshkey: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQCzxo5dEcS+LDK/OFAfHo6740EyoDM8aYaCkBala0FnWfMMTOq7PQe04ahB0eFLS3IlQtK5bpgzxBdFGVqF6uT5z4hhaPjQec0G3+BD5Pxo6V+SxShKZo+ZNGU3HVrF9p2V7QH0YFQj5B8F6AicA3fYh2BVUFECTPuMpy5A52ufWu0r4xOFmbU7SIhRQRAQz2u4yjXqBsrpYptAvyzzoN4gjUhNnwOHSPsvFpWoBFkWmqn0ytgHg3Vv9DlHW+45P02QH1UFedXR2MqLnwRI30qqtaOkVS+9rE/dhnR+XPpHHG+hv2TgMDAuQ3IK7Ab5m/yCbN73cxFifH4LST0vVG3Jx45xn+GTeHHhfkAfBSCtya6191jixbqyovpRunCBKexI5cfRPtWOitM3m7Mq26r7LpobMM+oOLUm4p0KKNIthWcmK9tYwXWSuGGfUQ+Y8gt7E0G06ZGbCPHOrxJ8lYQqXsif04piONPA/c9Hq43O99KPNGShONCS9oPFdOLRT3U= ostree-image-test
    Aug 24 06:02:32 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:32.445Z INFO  fdo_client_linuxapp              > Secure Device Onboarding DONE
    Aug 24 06:02:32 vm-3 fdo-client-linuxapp[1264]:  2023-08-24T10:02:32.445Z INFO  fdo_client_linuxapp              > Reboot required? false
    Aug 24 06:02:32 vm-3 systemd[1]: fdo-client-linuxapp.service: Deactivated successfully.
    Aug 24 06:02:32 vm-3 systemd[1]: Finished FDO client.
[admin@rhel-9-3-230824143429 ~]$ journalctl -u fdo-rendezvous-server.service --no-page
Aug 24 02:52:27 rhel-9-3-230824143429 systemd[1]: Started FDO rendezvous server.
Aug 24 02:52:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T06:52:27.155Z INFO  fdo_rendezvous_server > Listening on 0.0.0.0:8082
Aug 24 02:52:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T06:52:27.155Z INFO  fdo_rendezvous_server > Scheduling maintenance every 60 seconds
Aug 24 03:09:10 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:09:10.045Z WARN  fdo_http_wrapper::server > Error processing request: Rejection([Error(ErrorMessage { error_code: ResourceNotFound, previous_message_type: TO1HelloRV, error_string: "Device GUID not found", error_timestamp: None, error_uuid: 381166439307773600 }), MethodNotAllowed])
Aug 24 03:09:10 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:09:10.045Z INFO  rendezvous-server        > 192.168.100.50:38210 "POST /fdo/101/msg/30 HTTP/1.1" 500 "-" "-" 3.426467ms
Aug 24 03:09:10 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:09:10.049Z WARN  fdo_http_wrapper::server > Error processing request: Rejection(MethodNotAllowed)
Aug 24 03:09:10 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:09:10.049Z INFO  rendezvous-server        > 192.168.100.50:38210 "POST /fdo/101/msg/255 HTTP/1.1" 500 "-" "-" 62.097µs
Aug 24 03:09:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:09:27.259Z INFO  rendezvous-server        > 192.168.100.1:38486 "POST /fdo/101/msg/20 HTTP/1.1" 200 "-" "-" 1.984493ms
Aug 24 03:09:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:09:27.262Z INFO  fdo_rendezvous_server::handlers_to0 > Storing TO1D for device with GUID Guid([161, 21, 123, 72, 52, 65, 169, 133, 225, 139, 198, 10, 68, 184, 76, 7]) for Duration { seconds: 600, nanoseconds: 0 }
Aug 24 03:09:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:09:27.263Z INFO  rendezvous-server                   > 192.168.100.1:38486 "POST /fdo/101/msg/22 HTTP/1.1" 200 "-" "-" 3.812341ms
Aug 24 03:11:39 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:11:39.077Z INFO  rendezvous-server                   > 192.168.100.50:59470 "POST /fdo/101/msg/30 HTTP/1.1" 200 "-" "-" 658.496µs
Aug 24 03:11:39 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:11:39.081Z INFO  rendezvous-server                   > 192.168.100.50:59470 "POST /fdo/101/msg/32 HTTP/1.1" 200 "-" "-" 1.457304ms
Aug 24 03:23:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:23:27.319Z INFO  rendezvous-server                   > 192.168.100.1:47158 "POST /fdo/101/msg/20 HTTP/1.1" 200 "-" "-" 5.105717ms
Aug 24 03:23:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:23:27.321Z INFO  fdo_rendezvous_server::handlers_to0 > Storing TO1D for device with GUID Guid([209, 135, 212, 161, 43, 62, 237, 158, 248, 21, 171, 0, 207, 126, 146, 170]) for Duration { seconds: 600, nanoseconds: 0 }
Aug 24 03:23:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:23:27.321Z INFO  rendezvous-server                   > 192.168.100.1:47158 "POST /fdo/101/msg/22 HTTP/1.1" 200 "-" "-" 1.543054ms
Aug 24 03:23:38 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:23:38.545Z INFO  rendezvous-server                   > 192.168.100.51:39370 "POST /fdo/101/msg/30 HTTP/1.1" 200 "-" "-" 580.479µs
Aug 24 03:23:38 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:23:38.548Z INFO  rendezvous-server                   > 192.168.100.51:39370 "POST /fdo/101/msg/32 HTTP/1.1" 200 "-" "-" 1.251637ms
Aug 24 03:46:23 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:46:23.216Z WARN  fdo_http_wrapper::server            > Error processing request: Rejection([Error(ErrorMessage { error_code: ResourceNotFound, previous_message_type: TO1HelloRV, error_string: "Device GUID not found", error_timestamp: None, error_uuid: 12917522410090203354 }), MethodNotAllowed])
Aug 24 03:46:23 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:46:23.220Z INFO  rendezvous-server                   > 192.168.100.52:47330 "POST /fdo/101/msg/30 HTTP/1.1" 500 "-" "-" 14.729208ms
Aug 24 03:46:23 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:46:23.221Z WARN  fdo_http_wrapper::server            > Error processing request: Rejection(MethodNotAllowed)
Aug 24 03:46:23 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:46:23.221Z INFO  rendezvous-server                   > 192.168.100.52:47330 "POST /fdo/101/msg/255 HTTP/1.1" 500 "-" "-" 94.237µs
Aug 24 03:46:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:46:27.401Z INFO  rendezvous-server                   > 192.168.100.1:58820 "POST /fdo/101/msg/20 HTTP/1.1" 200 "-" "-" 255.56µs
Aug 24 03:46:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:46:27.402Z INFO  fdo_rendezvous_server::handlers_to0 > Storing TO1D for device with GUID Guid([16, 204, 209, 180, 119, 215, 143, 176, 43, 14, 165, 40, 235, 58, 200, 133]) for Duration { seconds: 600, nanoseconds: 0 }
Aug 24 03:46:27 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:46:27.402Z INFO  rendezvous-server                   > 192.168.100.1:58820 "POST /fdo/101/msg/22 HTTP/1.1" 200 "-" "-" 1.524179ms
Aug 24 03:48:23 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:48:23.249Z INFO  rendezvous-server                   > 192.168.100.52:46334 "POST /fdo/101/msg/30 HTTP/1.1" 200 "-" "-" 545.773µs
Aug 24 03:48:23 rhel-9-3-230824143429 fdo-rendezvous-server[24533]:  2023-08-24T07:48:23.253Z INFO  rendezvous-server                   > 192.168.100.52:46334 "POST /fdo/101/msg/32 HTTP/1.1" 200 "-" "-" 1.330696ms
nullr0ute commented 1 year ago

The T01 protocol is used for Client <-> rendezvous communications.

7flying commented 1 year ago

TL;DR: it's not a bug

In order for the TO1 protocol to work (device contacts rendezvous to get an address to contact its owner), the TO0 protocol must have been already performed (rendezvous is contacted by the owner to get a TO1d blob and the OV with a GUID, so that the rendezvous can know where to redirect the devices).

The log of the rendezvous server shows that it's rejecting a TO1HelloRV from a client since it has just started working, then it gets a couple of TO1D ( starting with the message type msg/20: 192.168.100.1:38486 "POST /fdo/101/msg/20 HTTP/1.1" 200 "-" "-" 1.984493ms) and it's storing some GUIDs as a result of that. Later it is processing the TO1 protocol as it should know now that it has GUIDs stored:

 192.168.100.50:59470 "POST /fdo/101/msg/30 HTTP/1.1" 200 "-" "-" 658.496µs
 192.168.100.50:59470 "POST /fdo/101/msg/32 HTTP/1.1" 200 "-" "-" 1.457304ms

the msg/30, msg/32 message types show that the client is properly communicating with the rendezvous, the rendezvous (not shown in the logs) is sending msg/31, msg/33, as it should (see this).

So, what I want to say is that timing is important here, it's a MUST to return a ResourceNotFound when no GUIDs are found by the rendezvous according to the GUID given by the client. Then, as the rendezvous gets GUIDs it is able to fulfill the requests of the client. So, not a bug.

7flying commented 1 year ago

Closing this as there is no action to take.