Get SDO support working with Intel's rendezvous server
bmpotter opened this issue · 8 comments
When using Intel's sbx rendezvous server (RV) with the key we have registered with it, registering the voucher with it (to0) works fine. But when the device boots and asks the RV what mgmt hub it should contact (t01), we get the error below. Not sure yet if it is a problem in our glue code or Intel's code. We are in discussions with Intel and they are currently debugging it. The somewhat good news is that this step doesn't involve the sdo container in the mgmt hub (it is between the device and Intel's RV), so it is likely that whatever fix is needed won't require a new version of the sdo mgmt hub container.
root@bp11:~/sdo# /usr/sdo/bin/owner-boot-device ibm.helloworld
Booting with java client...
13-10-2020 04:13:44.652 INFO [main] org.sdo.cri.device.DeviceApp.logStarting - Starting DeviceApp on bp11.fyre.ibm.com with PID 17389 (/var/sdo/sdo_device_binaries_1.8_linux_x64/device/device.jar started by root in /var/sdo/sdo_device_binaries_1.8_linux_x64/device)
13-10-2020 04:13:44.661 INFO [main] org.sdo.cri.device.DeviceApp.logStartupProfileInfo - No active profile set, falling back to default profiles: default
13-10-2020 04:13:45.805 INFO [main] org.sdo.cri.device.DeviceApp.logStarted - Started DeviceApp in 2.543 seconds (JVM running for 3.696)
13-10-2020 04:13:45.893 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.cipher-block-mode = CTR
13-10-2020 04:13:45.896 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.di.uri = http://localhost:8039
13-10-2020 04:13:45.898 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.pm.credmfg.d = SDO Java Device
13-10-2020 04:13:45.901 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.device.output-dir = creds/saved
13-10-2020 04:13:45.911 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.device.output-dir = [NativePRNG, Windows-PRNG, SHA1PRNG]
13-10-2020 04:13:45.915 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.device.serial = 28ec2879cd815f0ef5846e1ec3397a3da3b91ea81522d5e3a1bf078a2cd44
13-10-2020 04:13:45.917 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.device.stop-after-di = true
13-10-2020 04:13:45.921 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.device.cert = file:/var/sdo/sdo_device_binaries_1.8_linux_x64/device/creds/device.crt
13-10-2020 04:13:45.923 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.device.credentials = file:/var/sdo/sdo_device_binaries_1.8_linux_x64/device/creds/0dc5c5ac-2ddc-494f-a338-a575a84e55f9.oc
13-10-2020 04:13:45.925 INFO [main] org.sdo.cri.device.DeviceApp.logProperty - property org.sdo.device.key = file:/var/sdo/sdo_device_binaries_1.8_linux_x64/device/creds/device.key
13-10-2020 04:13:46.005 INFO [main] org.sdo.cri.device.DeviceApp.lambda$applicationRunner$1 - device onboarding begins
13-10-2020 04:13:46.325 INFO [main] org.sdo.cri.device.DeviceApp.secureRandom - using SecureRandom NativePRNG
13-10-2020 04:13:46.329 WARN [main] org.sdo.cri.device.DeviceApp.sslContext - UNSAFE: no-op TrustManager installed
13-10-2020 04:13:46.558 INFO [main] o.s.c.DeviceTransferOwnershipClient.httpPost - HttpRequest: http://sdo-sbx.trustedservices.intel.com/mp/113/msg/30 POST
{Content-Type=[application/json]}
{"g2":"DcXFrC3cSU+jOKV1qE5V+Q==","eA":[13,0,""]}
13-10-2020 04:13:47.081 INFO [main] o.s.c.DeviceTransferOwnershipClient.httpPost - HttpResponse: (POST http://sdo-sbx.trustedservices.intel.com/mp/113/msg/30) 400
{connection=[keep-alive], content-length=[54], content-type=[text/html;charset=iso-8859-1], date=[Tue, 13 Oct 2020 11:13:46 GMT]}
<h1>Bad Message 400</h1><pre>reason: Bad Request</pre>
13-10-2020 04:13:47.088 ERROR [main] o.s.c.DeviceTransferOwnershipClient.call - (POST http://sdo-sbx.trustedservices.intel.com/mp/113/msg/30) 400 <h1>Bad Message 400</h1><pre>reason: Bad Request</pre>
13-10-2020 04:13:47.146 INFO [main] o.s.c.DeviceTransferOwnershipClient.call - All rendezvous instructions exhausted. Pausing until Oct 13, 2020, 4:15:36 AM
TO1 is successful using Intel SBX RV server SDO_RV_URL=http://sdo-sbx.trustedservices.intel.com:80
with the Intel Nuc. Without the port number, it will not work for me.
Oct 30 13:59:24 rtpnuc01 bash[19498]: Starting TO1
Oct 30 13:59:24 rtpnuc01 bash[19498]: ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:316 Proxy enabled but Not set
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:316 using DNS: sdo-sbx.trustedservices.intel.com
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:316 Resolving DNS-URL: sdo-sbx.trustedservices.intel.com
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:387 Connecting to Rendezvous server
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:387 Proxy enabled but Not set
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:387 using IP
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:404 Rest Header write returns 193/193 bytes
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:404 REST:header(193):POST http://sdo-sbx.trustedservices.intel.com:80/mp/113/msg/30 HTTP/1.1
Oct 30 13:59:24 rtpnuc01 bash[19498]: HOST:sdo-sbx.trustedservices.intel.com:80
Oct 30 13:59:24 rtpnuc01 bash[19498]: Content-type:application/json
Oct 30 13:59:24 rtpnuc01 bash[19498]: Content-length:48
Oct 30 13:59:24 rtpnuc01 bash[19498]: _connection: keep-alive
Oct 30 13:59:24 rtpnuc01 bash[19498]: [1B blob data]
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:404 Rest Body write returns 48/48 bytes
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:404 Tx sdo_prot_ctx_run:body:{"g2":"3STS8qV8Q5qprx3Mq7RJCA==","eA":[13,0,""]}
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 REST: HTTP response line: HTTP/1.1 200 OK
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Response code 200 received (OK)
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Body: Date
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Content type: application/json
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Content-length: 48
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Keep alive: 1
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Authorization: Bearer eyJhbGciOiJIUzI1NiJ9.eyJuNCI6IklFRTYzTFNnN0plNDkxbVoycWpvS3c9PSIsImcyIjoiM1NUUzhxVjhRNXFwcngzTXE3UkpDQT09IiwiZXhwIjoxNjA0MDgxNjY0fQ.LRUyIF9sm9caVOMrA4du49c6YSc_JtQU8h0Ob4k9pgo
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Rx sdo_prot_ctx_run:body:{"n4":"IEE63LSg7Je491mZ2qjoKw==","eB":[13,0,""]}
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 SDOProtTO1: Received message type 0 : 48 bytes
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Byte Array len 20
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Received n4: [20413ADCB4A0EC97B8F75999DAA8E82B]
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Received ecdsa EB of len: 0
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:449 Starting SDO_STATE_TO1_SND_PROVE_TO_SDO
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:450 Complete SDO_STATE_TO1_SND_PROVE_TO_SDO
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:450
Oct 30 13:59:24 rtpnuc01 bash[19498]: _starting SDO_STATE_TO1_RCV_SDO_REDIRECT
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:450 Connecting to Rendezvous server
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:450 Proxy enabled but Not set
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:450 using IP
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:463 Rest Header write returns 392/392 bytes
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:463 REST:header(392):POST http://sdo-sbx.trustedservices.intel.com:80/mp/113/msg/32 HTTP/1.1
Oct 30 13:59:24 rtpnuc01 bash[19498]: HOST:sdo-sbx.trustedservices.intel.com:80
Oct 30 13:59:24 rtpnuc01 bash[19498]: Content-type:application/json
Oct 30 13:59:24 rtpnuc01 bash[19498]: Content-length:218
Oct 30 13:59:24 rtpnuc01 bash[19498]: _connection: keep-alive
Oct 30 13:59:24 rtpnuc01 bash[19498]: Authorization:Bearer eyJhbGciOiJIUzI1NiJ9.eyJuNCI6IklFRTYzTFNnN0plNDkxbVoycWpvS3c9PSIsImcyIjoiM1NUUzhxVjhRNXFwcngzTXE3UkpDQT09IiwiZXhwIjoxNjA0MDgxNjY0fQ.LRUyIF9sm9caVOMrA4du49c6YSc_JtQU8h0Ob4k9pgo
Oct 30 13:59:24 rtpnuc01 bash[19498]: [1B blob data]
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:463 Rest Body write returns 218/218 bytes
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:463 Tx sdo_prot_ctx_run:body:{"bo":{"ai":[4,2,"AQIDBA=="],"n4":"IEE63LSg7Je491mZ2qjoKw==","g2":"3STS8qV8Q5qprx3Mq7RJCA=="},"pk":[0,0,[0]],"sg":[72,"MEYCIQCnNv9nrdWZUr5tLaQj315MrYo0f5+n7P71DWzI/HZ60gIhAM5Rk14QjFBBbEONkA1HkQ8chASjSd+Og8/6yY9BVAEA"]}
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 REST: HTTP response line: HTTP/1.1 200 OK
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 Response code 200 received (OK)
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 Body: Date
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 Content type: application/json
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 Content-length: 339
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 Keep alive: 1
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 Authorization: Bearer eyJhbGciOiJIUzI1NiJ9.eyJuNCI6IklFRTYzTFNnN0plNDkxbVoycWpvS3c9PSIsImcyIjoiM1NUUzhxVjhRNXFwcngzTXE3UkpDQT09IiwiZXhwIjoxNjA0MDgxNjY0fQ.LRUyIF9sm9caVOMrA4du49c6YSc_JtQU8h0Ob4k9pgo
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 Rx sdo_prot_ctx_run:body:{"bo":{"i1":[4,"fwAAAQ=="],"dns1":"ibm-edge-sdo-ops.ieam-roks-stg-70ea81cdef68a2eb78ece6d890b7dad3-0000.us-south.containers.appdomain.cloud","port1":80,"to0dh":[32,8,"whbWqsN5kTq5yv3eHmJkI1DFar4gqMrgBlB63DLqrso="]},"pk":[0,0,[0]],"sg":[71,"MEUCIQCW48ssiwDIomwQXmNqmr+N9ytPtWddO8jFiG9FoClogQIgRdGIbzjFcZNmiunUEGCQZHRQSn+RNJ9cHQd6qfVHIvM="]}
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504
Oct 30 13:59:24 rtpnuc01 bash[19498]: _starting SDO_STATE_TO1_RCV_SDO_REDIRECT
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 SDOProtTO1: Received message type 0 : 339 bytes
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 Received redirect: [IPv4:127.0.0.1]
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504 Complete SDO_STATE_TO1_RCV_SDO_REDIRECT
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504
Oct 30 13:59:24 rtpnuc01 bash[19498]: ------------------------------------ TO1 Successful --------------------------------------
Oct 30 13:59:24 rtpnuc01 bash[19498]: 17:59:24:504```
TO2 will not successfully complete though. After this message repeated a bunch of times
Oct 30 14:02:43 rtpnuc01 bash[19498]: Starting TO2
Oct 30 14:02:43 rtpnuc01 bash[19498]: ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:201 kex name (ECDH) used
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:201 compute_publicB started
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:202 compute_publicB complete
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:202 SDO_STATE_T02_SND_HELLO_DEVICE: Starting
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:202 Sending n5: [9CC29825A638BEA027085C00C096A40A]
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:202 SDO_STATE_T02_SND_HELLO_DEVICE: Complete
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:202 SDO_STATE_TO2_RCV_PROVE_OVHDR: Starting
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:202 Proxy enabled but Not set
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:202 using DNS: ibm-edge-sdo-ops.ieam-roks-stg-70ea81cdef68a2eb78ece6d890b7dad3-0000.us-south.containers.appdomain.cloud
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:202 Resolving DNS-URL: <ibm-edge-sdo-ops.ieam-roks-stg-70ea81cdef68a2eb78ece6d890b7dad3-0000.us-south.containers.appdomain.cloud>
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:253 Connecting to owner server
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:253 Proxy enabled but Not set
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:253 using IP
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:313 Rest Header write returns 336/336 bytes
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:313 REST:header(336):POST http://ibm-edge-sdo-ops.ieam-roks-stg-70ea81cdef68a2eb78ece6d890b7dad3-0000.us-south.containers.appdomain.cloud:80/mp/113/msg/40 HTTP/1.1
Oct 30 14:02:43 rtpnuc01 bash[19498]: HOST:ibm-edge-sdo-ops.ieam-roks-stg-70ea81cdef68a2eb78ece6d890b7dad3-0000.us-south.containers.appdomain.cloud:80
Oct 30 14:02:43 rtpnuc01 bash[19498]: Content-type:application/json
Oct 30 14:02:43 rtpnuc01 bash[19498]: Content-length:129
Oct 30 14:02:43 rtpnuc01 bash[19498]: _connection: keep-alive
Oct 30 14:02:43 rtpnuc01 bash[19498]: [1B blob data]
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:313 Rest Body write returns 129/129 bytes
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:313 Tx sdo_prot_ctx_run:body:{"g2":"3STS8qV8Q5qprx3Mq7RJCA==","n5":"nMKYJaY4vqAnCFwAwJakCg==","pe":1,"kx":"ECDH","cs":"AES128/CTR/HMAC-SHA256","eA":[13,0,""]}
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:597 REST: HTTP response line: HTTP/1.1 200
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:597 Response code 200 received ()
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:597 Authorization: Bearer DD24D2F2A57C439AA9AF1DCCABB44908
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:597 Content type: application/json
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:597 Content-length: 889
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:597 Body: date
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:597 Body: set-cookie
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Rx sdo_prot_ctx_run:body:{"bo":{"sz":1,"oh":{"pv":113,"pe":1,"r":[1,[4,{"dn":"sdo-sbx.trustedservices.intel.com","po":80,"pow":80,"pr":"http"}]],"g":"3STS8qV8Q5qprx3Mq7RJCA==","d":"0","pk":[13,1,[91,"MFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAE6+Yq304FMQeer35r6h/gt/s0lruFYoy6rJBiy2YvUCaCSwqpX5c62u/4xNbVzDj2Nw0TVod6cGlNo+WknJkZcA=="]],"hdc":[32,8,"pXhdIdRuQo1C/kG+8nyoqfQKuOvS9MbYf5zWamCms6Y="]},"hmac":[32,108,"b4s43VoQP5wFGzghWj7fr7OhF3Novo/fRJSrDZSWBp4="],"n5":"nMKYJaY4vqAnCFwAwJakCg==","n6":"h+bKENR3k+0naXAQ8Z9nTw==","eB":[13,0,""],"xA":[86,"ACCKXQ3PbddPIZca0zloxYUkSlsp0wo9WnQEawfExnCJkgAgVtQ3Bss9x9dXJai6JRVuXNEHSj4oynXTCv+xKF1PUCoAEHsPDDFXdybsofzpHTSK1K0="]},"pk":[13,1,[91,"MFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAEUdKlTX/MyJeZlZT243L6y535kwpkydviX9zFbXitT02MS6R6C4xdth4IgrfvdMQh4cNhJXDoBHUbWx6PAyZflA=="]],"sg":[71,"MEUCIQDV0JUXO2YiqhZJjIJldod2w+UOuMUpS5zPJfR8/Wx7hwIgJey8PgkfGfLmzBP1K9DHTsPM+tQfwqtGn1kV3ykKxSI="]}
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 SDO_STATE_TO2_RCV_PROVE_OVHDR: Starting
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 SDOProtTO2: Received message type 0 : 889 bytes
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 There should be 1 entries in the rvlst
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 rv_index 0
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 New rv allocated 0x563bb8d193e0
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 sdo_rendezvous_read started
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Adding to rvlst
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Added to rvlst, 1 entries
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 sdo_rendezvous_list_read read
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Byte Array len 20
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Public_key_read Key1 read, 91 bytes
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Public_key_read pkalg: 13. pkenc: 1, key1: 91, key2: 0
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 sdo_end_readHMAC.plain_text: {"pv":113,"pe":1,"r":[1,[4,{"dn":"sdo-sbx.trustedservices.intel.com","po":80,"pow":80,"pr":"http"}]],"g":"3STS8qV8Q5qprx3Mq7RJCA==","d":"0","pk":[13,1,[91,"MFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAE6+Yq304FMQeer35r6h/gt/s0lruFYoy6rJBiy2YvUCaCSwqpX5c62u/4xNbVzDj2Nw0TVod6cGlNo+WknJkZcA=="]],"hdc":[32,8,"pXhdIdRuQo1C/kG+8nyoqfQKuOvS9MbYf5zWamCms6Y="]}
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 sdo_end_readHMAC: [Secret:[32]:A33072AA720C4B2D89312E9520CBE851D0473225F99608F317FEFE1CF2100269]
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Total number of Ownership Vouchers: 1
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Valid Ownership Header received
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Byte Array len 20
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Received n5r: [9CC29825A638BEA027085C00C096A40A]
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Byte Array len 20
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Received n6: [87E6CA10D47793ED27697010F19F674F]
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Received ecdsa EB of len: 0
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Key Exchange xA is 86 bytes
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Public_key_read Key1 read, 91 bytes
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 Public_key_read pkalg: 13. pkenc: 1, key1: 91, key2: 0
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 sdo_end_read_signature.Sig_text: {"sz":1,"oh":{"pv":113,"pe":1,"r":[1,[4,{"dn":"sdo-sbx.trustedservices.intel.com","po":80,"pow":80,"pr":"http"}]],"g":"3STS8qV8Q5qprx3Mq7RJCA==","d":"0","pk":[13,1,[91,"MFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAE6+Yq304FMQeer35r6h/gt/s0lruFYoy6rJBiy2YvUCaCSwqpX5c62u/4xNbVzDj2Nw0TVod6cGlNo+WknJkZcA=="]],"hdc":[32,8,"pXhdIdRuQo1C/kG+8nyoqfQKuOvS9MbYf5zWamCms6Y="]},"hmac":[32,108,"b4s43VoQP5wFGzghWj7fr7OhF3Novo/fRJSrDZSWBp4="],"n5":"nMKYJaY4vqAnCFwAwJakCg==","n6":"h+bKENR3k+0naXAQ8Z9nTw==","eB":[13,0,""],"xA":[86,"ACCKXQ3PbddPIZca0zloxYUkSlsp0wo9WnQEawfExnCJkgAgVtQ3Bss9x9dXJai6JRVuXNEHSj4oynXTCv+xKF1PUCoAEHsPDDFXdybsofzpHTSK1K0="]}
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:598 sdo_end_read_signature.PK:
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:599 Signature verifies OK.
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:600 Signature verifies OK.
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:600 sdo_redirect verification Successful
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:600 SDO_STATE_TO2_RCV_PROVE_OVHDR: Complete, 1 ov_entries to follow
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:601 SDO_STATE_TO2_SND_GET_OP_NEXT_ENTRY: Starting
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:601 SDO_STATE_T02_RCV_OP_NEXT_ENTRY: Starting
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:601 Connecting to owner server
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:601 Proxy enabled but Not set
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:601 using IP
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:649 Rest Header write returns 389/389 bytes
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:649 REST:header(389):POST http://ibm-edge-sdo-ops.ieam-roks-stg-70ea81cdef68a2eb78ece6d890b7dad3-0000.us-south.containers.appdomain.cloud:80/mp/113/msg/42 HTTP/1.1
Oct 30 14:02:43 rtpnuc01 bash[19498]: HOST:ibm-edge-sdo-ops.ieam-roks-stg-70ea81cdef68a2eb78ece6d890b7dad3-0000.us-south.containers.appdomain.cloud:80
Oct 30 14:02:43 rtpnuc01 bash[19498]: Content-type:application/json
Oct 30 14:02:43 rtpnuc01 bash[19498]: Content-length:9
Oct 30 14:02:43 rtpnuc01 bash[19498]: _connection: keep-alive
Oct 30 14:02:43 rtpnuc01 bash[19498]: Authorization:Bearer DD24D2F2A57C439AA9AF1DCCABB44908
Oct 30 14:02:43 rtpnuc01 bash[19498]: [1B blob data]
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:649 Rest Body write returns 9/9 bytes
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:649 Tx sdo_prot_ctx_run:body:{"enn":0}
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:760 REST: HTTP response line: HTTP/1.1 200
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:760 Response code 200 received ()
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:760 Authorization: Bearer DD24D2F2A57C439AA9AF1DCCABB44908
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:760 Content type: application/json
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:760 Content-length: 410
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:760 Body: date
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:760 Body: set-cookie
Oct 30 14:02:43 rtpnuc01 bash[19498]: 18:02:43:760 Rx sdo_prot_ctx_run:body:{"enn":0,"eni":{"bo":{"hp":[32,8,"NBxhs0YzrNXcBb5sATtZy+JIV/ep8h5KyaoKGsH5+5g="],"hc":[32,8,"hD7us9PXdnWRJAO7EWIGjgTQaC+79e1wOlxY87zzJew="],"pk":[13,1,[91,"MFkwEwYHKoZIzj0CAQYIKoZIzj0DAQcDQgAEUdKlTX/MyJeZlZT243L6y535kwpkydviX9zFbXitT02MS6R6C4xdth4IgrfvdMQh4cNhJXDoBHUbWx6PAyZflA=="]]},"pk":[0,0,[0]],"sg":[71,"MEUCIQDgc2oGK2qoUlmLVTyYjtzl5ht+Cdha4fzzRhlPxAnOpQIgA6+NzmLxSeybZqrVMVHJVHl0VEF6haxsQKrp+Hc8ep4="]}}
I eventually received
Oct 30 14:03:12 rtpnuc01 bash[19498]: 18:03:12:659 SDOProtTO2: Received message type 0 : 1434 bytes
Oct 30 14:03:12 rtpnuc01 bash[19498]: 18:03:12:659 OSI_KV pair:
Oct 30 14:03:12 rtpnuc01 bash[19498]: _key->sdo_sys:write,Value->R0VfQ0xVU1RFUl9SRUdJU1RSWS8kRURHRV9DTFVTVEVSX1JFR0lTVFJZX1BST0pFQ1RfTkFNRS8kRURHRV9DTFVTVEVSX0FHRU5UX0lNQUdFX0FORF9UQUcKICAgICAgICBmaQogICAgICAgIHNlZCAtaSAtZSAicyNfX0ltYWdlUGF0aF9fIyR7aW1hZ2VfZnVsbF9wYXRoX29uX2VkZ2VfY2x1c3Rlcl9yZWdpc3RyeV9pbnRlcm5hbF91cmx9I2ciIGRlcGxveW1lbnQueW1sCiAgICBlbHNlCiAgICAgICAgbG9nX2ZhdGFsIDEgIkFnZW50IGluc3RhbGwgb24gZWRnZSBjbHVzdGVyIHJlcXVpcmVzIHVzaW5nIGFuIGVkZ2UgY2x1c3RlciByZWdpc3RyeSIKICAgICAgICAjc2VkIC1pIC1lICJzI19fSW1hZ2VQYXRoX18jJHtBR0VOVF9JTUFHRX0jZyIgZGVwbG95bWVudC55bWwKICAgIGZpCgogICAgbG9nX2RlYnVnICJwcmVwYXJlX2s4c19kZXBsb3ltZW50X2ZpbGUoKSBlbmQiCn0KCiMgQ2x1c3RlciBvbmx5OiB0byBjcmVhdGUgcGVyc2lzdGVuQ2xhaW0ueW1sIGJhc2VkIG9uIHRlbXBsYXRlCmZ1bmN0aW9uIHByZXBhcmVfazhzX3B2Y19maWxlKCkgewogICAgbG9nX2RlYnVnICJwcmVwYXJlX2s4c19wdmNfZmlsZSgpIGJlZ2luIgoKICAgICMgTm90ZTogZ2V0X2VkZ2VfY2x1c3Rlcl9maWxlcygpIGFscmVhZHkgZG93bmxvYWRlZCBkZXBsb3ltZW50LXRlbXBsYXRlLnltbCwgaWYgbmVjZXNzYXJ5CgogICAgc2VkIC1lICJzI19fQWdlbnROYW1lU3BhY2VfXyMke0FHRU5U
Oct 30 14:03:12 rtpnuc01 bash[19498]: 18:03:12:660 Connecting to owner server
Oct 30 14:03:21 rtpnuc01 systemd[1]: sdo_to.service: Main process exited, code=exited, status=127/n/a
Oct 30 14:03:21 rtpnuc01 systemd[1]: sdo_to.service: Failed with result 'exit-code'.
Oct 30 14:03:21 rtpnuc01 systemd[1]: Failed to start SDO boot-time TO1 and TO2 run-once service.```
Received a fix from Intel for the device.jar
client used for VMs. It successfully used http://sdo-sbx.trustedservices.intel.com:80 . Now waiting for them to publish the fixed device.jar
in the official location: https://github.com/secure-device-onboard/release/releases/download/v1.8.0/pri-v1.8.0.tar.gz
Also still investigating using http://sdo-sbx.trustedservices.intel.com:80 in the Intel NUC.
Intel NUC works with http://sdo-sbx.trustedservices.intel.com:80 .
So now only waiting for them to publish the fixed device.jar in the official location: https://github.com/secure-device-onboard/release/releases/download/v1.8.0/pri-v1.8.0.tar.gz
@bmpotter Please either close this issue (if completed or no longer relevant), or change the release to Winter
or Future
Release.
@bmpotter Please either close this issue (if completed or no longer relevant), or change the release to Winter or Future Release.
Intel has published the fixed device.jar at https://github.com/secure-device-onboard/release/releases/download/v1.8.1/pri-v1.8.1.tar.gz . Now i have to:
- Pull that into SDO-support and recreate
sample-mfg/sdo_device_binaries_1.9_linux_x64.tar.gz
- Test a VM with sbx RV
- Publish the changes to https://github.com/open-horizon/SDO-support/releases/tag/v1.8
Decided not to update 1.8, because we are switching to 1.9 very soon.