I, [2019-05-27T08:20:37.623202 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 08:20:37 +0000 I, [2019-05-27T08:20:37.634299 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T08:20:37.636668 #1] DEBUG -- : (0.4ms) BEGIN D, [2019-05-27T08:20:37.639323 #1] DEBUG -- : CmsVoucherRequest Create (0.9ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T08:20:37.000+00:00\",\"nonce\":\"0640552654342737\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 08:20:37.637003"], ["updated_at", "2019-05-27 08:20:37.637003"]] D, [2019-05-27T08:20:37.679118 #1] DEBUG -- : (39.2ms) COMMIT D, [2019-05-27T08:20:37.681203 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:20:37.682245 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T08:20:37.684236 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:20:37.685556 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:20:37.687084 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] I, [2019-05-27T08:20:37.687403 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T08:20:37.687797 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:20:37.691118 #1] DEBUG -- : CmsVoucherRequest Update (2.0ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 5], ["manufacturer_id", 1], ["device_identifier", "0123456789"], ["proxy_ip", "80.146.228.121"], ["nonce", "0640552654342737"], ["updated_at", "2019-05-27 08:20:37.688205"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIB2jCCAYCgAwIBAgIGAWegdcSLMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE4MTIxMjAzMjg1MVoYDzk5OTkxMjMxMjM1OTU5WjBSMQswCQYDVQQGEwJB\nUTEVMBMGA1UECgwMSmluZ0ppbmdDb3JwMRMwEQYDVQQFEwowMTIzNDU2Nzg5MRcw\nFQYDVQQDDA5KaW5nSmluZ0RldmljZTBZMBMGByqGSM49AgEGCCqGSM49AwEHA0IA\nBMVGG8Z5pjf5jXnyrUrXyZ1kPgqBe3NXu1dTADe+r/v6JzIHl355IgcHC3axpibq\nJM/bWRaEyjqcCJj4jJkowCujVTBTMCwGCSsGAQQBgu5SAgQfDB1tYXNhLXRlc3Qu\nc2llbWVucy1idC5uZXQ6OTQ0MzATBgNVHSUEDDAKBggrBgEFBQcDAjAOBgNVHQ8B\nAf8EBAMCB4AwCgYIKoZIzj0EAwIDSAAwRQIgWtPzIIXY2ixRXJtExKEhhZda4X+E\nplZomEI2zA0dsjoCIQC3JpQmRXMGn/p4Bu9izii92eclTx4/O4rlm7MyLqkhdA==\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1656 bytes of binary data>"], ["id", 27]] D, [2019-05-27T08:20:37.712469 #1] DEBUG -- : (20.8ms) COMMIT D, [2019-05-27T08:20:37.713729 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:20:37.714630 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:20:37.715939 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:20:37.716866 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:20:37.718011 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] D, [2019-05-27T08:20:37.718675 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:20:37.719573 #1] DEBUG -- : (0.2ms) COMMIT I, [2019-05-27T08:20:37.719823 #1] INFO -- : Contacting server at: https://masa-test.siemens-bt.net:9443/.well-known/est/requestvoucher about 0123456789 [27] I, [2019-05-27T08:20:37.719898 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T08:20:37.720359 #1] INFO -- : Completed 500 Internal Server Error in 86ms (ActiveRecord: 67.6ms) I, [2019-05-27T08:21:00.236268 #1] INFO -- : Started GET "/status" for 80.146.228.121 at 2019-05-27 08:21:00 +0000 I, [2019-05-27T08:21:00.294445 #1] INFO -- : Processing by StatusController#index as HTML D, [2019-05-27T08:21:00.297456 #1] DEBUG -- : (2.1ms) SELECT COUNT(*) FROM "certificates" D, [2019-05-27T08:21:00.299059 #1] DEBUG -- : (1.2ms) SELECT COUNT(*) FROM "vouchers" D, [2019-05-27T08:21:00.301007 #1] DEBUG -- : (1.5ms) SELECT COUNT(*) FROM "voucher_requests" I, [2019-05-27T08:21:00.303550 #1] INFO -- : Rendering status/index.html.erb within layouts/reload I, [2019-05-27T08:21:00.303752 #1] INFO -- : Rendered status/index.html.erb within layouts/reload (0.1ms) I, [2019-05-27T08:21:00.304017 #1] INFO -- : Completed 200 OK in 9ms (Views: 2.5ms | ActiveRecord: 4.7ms) I, [2019-05-27T08:21:25.993999 #1] INFO -- : Started GET "/status" for 80.146.228.121 at 2019-05-27 08:21:25 +0000 I, [2019-05-27T08:21:26.005259 #1] INFO -- : Processing by StatusController#index as HTML D, [2019-05-27T08:21:26.007148 #1] DEBUG -- : (1.1ms) SELECT COUNT(*) FROM "certificates" D, [2019-05-27T08:21:26.008230 #1] DEBUG -- : (0.4ms) SELECT COUNT(*) FROM "vouchers" D, [2019-05-27T08:21:26.009029 #1] DEBUG -- : (0.4ms) SELECT COUNT(*) FROM "voucher_requests" I, [2019-05-27T08:21:26.011427 #1] INFO -- : Rendering status/index.html.erb within layouts/reload I, [2019-05-27T08:21:26.011614 #1] INFO -- : Rendered status/index.html.erb within layouts/reload (0.1ms) I, [2019-05-27T08:21:26.011872 #1] INFO -- : Completed 200 OK in 6ms (Views: 2.4ms | ActiveRecord: 1.9ms) I, [2019-05-27T08:21:36.825271 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 08:21:36 +0000 I, [2019-05-27T08:21:36.836441 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T08:21:36.838749 #1] DEBUG -- : (0.4ms) BEGIN D, [2019-05-27T08:21:36.842035 #1] DEBUG -- : CmsVoucherRequest Create (1.7ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T08:21:36.000+00:00\",\"nonce\":\"1353093769992930\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 08:21:36.839083"], ["updated_at", "2019-05-27 08:21:36.839083"]] D, [2019-05-27T08:21:36.877694 #1] DEBUG -- : (34.9ms) COMMIT D, [2019-05-27T08:21:36.882312 #1] DEBUG -- : Device Load (1.8ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:21:36.901557 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:21:36.903302 #1] DEBUG -- : (0.3ms) COMMIT D, [2019-05-27T08:21:36.905803 #1] DEBUG -- : Manufacturer Load (1.0ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:21:36.913521 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] I, [2019-05-27T08:21:36.913841 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T08:21:36.914258 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:21:36.918990 #1] DEBUG -- : CmsVoucherRequest Update (3.3ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 5], ["manufacturer_id", 1], ["device_identifier", "0123456789"], ["proxy_ip", "80.146.228.121"], ["nonce", "1353093769992930"], ["updated_at", "2019-05-27 08:21:36.914732"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIB2jCCAYCgAwIBAgIGAWegdcSLMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE4MTIxMjAzMjg1MVoYDzk5OTkxMjMxMjM1OTU5WjBSMQswCQYDVQQGEwJB\nUTEVMBMGA1UECgwMSmluZ0ppbmdDb3JwMRMwEQYDVQQFEwowMTIzNDU2Nzg5MRcw\nFQYDVQQDDA5KaW5nSmluZ0RldmljZTBZMBMGByqGSM49AgEGCCqGSM49AwEHA0IA\nBMVGG8Z5pjf5jXnyrUrXyZ1kPgqBe3NXu1dTADe+r/v6JzIHl355IgcHC3axpibq\nJM/bWRaEyjqcCJj4jJkowCujVTBTMCwGCSsGAQQBgu5SAgQfDB1tYXNhLXRlc3Qu\nc2llbWVucy1idC5uZXQ6OTQ0MzATBgNVHSUEDDAKBggrBgEFBQcDAjAOBgNVHQ8B\nAf8EBAMCB4AwCgYIKoZIzj0EAwIDSAAwRQIgWtPzIIXY2ixRXJtExKEhhZda4X+E\nplZomEI2zA0dsjoCIQC3JpQmRXMGn/p4Bu9izii92eclTx4/O4rlm7MyLqkhdA==\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1657 bytes of binary data>"], ["id", 28]] D, [2019-05-27T08:21:36.932829 #1] DEBUG -- : (13.4ms) COMMIT D, [2019-05-27T08:21:36.934010 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:21:36.934923 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:21:36.936196 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:21:36.937103 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:21:36.938200 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] D, [2019-05-27T08:21:36.938903 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:21:36.939814 #1] DEBUG -- : (0.2ms) COMMIT I, [2019-05-27T08:21:36.940065 #1] INFO -- : Contacting server at: https://masa-test.siemens-bt.net:9443/.well-known/est/requestvoucher about 0123456789 [28] I, [2019-05-27T08:21:36.940161 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T08:21:36.940614 #1] INFO -- : Completed 500 Internal Server Error in 104ms (ActiveRecord: 82.9ms) I, [2019-05-27T08:21:46.917543 #1] INFO -- : Started GET "/status" for 80.146.228.121 at 2019-05-27 08:21:46 +0000 I, [2019-05-27T08:21:46.928978 #1] INFO -- : Processing by StatusController#index as HTML D, [2019-05-27T08:21:46.930248 #1] DEBUG -- : (0.5ms) SELECT COUNT(*) FROM "certificates" D, [2019-05-27T08:21:46.931093 #1] DEBUG -- : (0.4ms) SELECT COUNT(*) FROM "vouchers" D, [2019-05-27T08:21:46.931889 #1] DEBUG -- : (0.4ms) SELECT COUNT(*) FROM "voucher_requests" I, [2019-05-27T08:21:46.934125 #1] INFO -- : Rendering status/index.html.erb within layouts/reload I, [2019-05-27T08:21:46.934313 #1] INFO -- : Rendered status/index.html.erb within layouts/reload (0.1ms) I, [2019-05-27T08:21:46.934621 #1] INFO -- : Completed 200 OK in 5ms (Views: 2.3ms | ActiveRecord: 1.3ms) I, [2019-05-27T08:27:21.521770 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 08:27:21 +0000 I, [2019-05-27T08:27:21.533160 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T08:27:21.535688 #1] DEBUG -- : (0.4ms) BEGIN D, [2019-05-27T08:27:21.537895 #1] DEBUG -- : CmsVoucherRequest Create (0.7ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T08:27:21.000+00:00\",\"nonce\":\"0122369224164056\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 08:27:21.536027"], ["updated_at", "2019-05-27 08:27:21.536027"]] D, [2019-05-27T08:27:21.588602 #1] DEBUG -- : (50.1ms) COMMIT D, [2019-05-27T08:27:21.590973 #1] DEBUG -- : Device Load (0.6ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:27:21.591927 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:27:21.593492 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:27:21.594812 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:27:21.596281 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] I, [2019-05-27T08:27:21.596600 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T08:27:21.597005 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:27:21.599922 #1] DEBUG -- : CmsVoucherRequest Update (1.6ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 5], ["manufacturer_id", 1], ["device_identifier", "0123456789"], ["proxy_ip", "80.146.228.121"], ["nonce", "0122369224164056"], ["updated_at", "2019-05-27 08:27:21.597418"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIB2jCCAYCgAwIBAgIGAWegdcSLMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE4MTIxMjAzMjg1MVoYDzk5OTkxMjMxMjM1OTU5WjBSMQswCQYDVQQGEwJB\nUTEVMBMGA1UECgwMSmluZ0ppbmdDb3JwMRMwEQYDVQQFEwowMTIzNDU2Nzg5MRcw\nFQYDVQQDDA5KaW5nSmluZ0RldmljZTBZMBMGByqGSM49AgEGCCqGSM49AwEHA0IA\nBMVGG8Z5pjf5jXnyrUrXyZ1kPgqBe3NXu1dTADe+r/v6JzIHl355IgcHC3axpibq\nJM/bWRaEyjqcCJj4jJkowCujVTBTMCwGCSsGAQQBgu5SAgQfDB1tYXNhLXRlc3Qu\nc2llbWVucy1idC5uZXQ6OTQ0MzATBgNVHSUEDDAKBggrBgEFBQcDAjAOBgNVHQ8B\nAf8EBAMCB4AwCgYIKoZIzj0EAwIDSAAwRQIgWtPzIIXY2ixRXJtExKEhhZda4X+E\nplZomEI2zA0dsjoCIQC3JpQmRXMGn/p4Bu9izii92eclTx4/O4rlm7MyLqkhdA==\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1655 bytes of binary data>"], ["id", 29]] D, [2019-05-27T08:27:21.621797 #1] DEBUG -- : (21.4ms) COMMIT D, [2019-05-27T08:27:21.623017 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:27:21.623861 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:27:21.625145 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:27:21.626070 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:27:21.627221 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] D, [2019-05-27T08:27:21.627852 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:27:21.628742 #1] DEBUG -- : (0.2ms) COMMIT I, [2019-05-27T08:27:21.628992 #1] INFO -- : Contacting server at: https://masa-test.siemens-bt.net:9443/.well-known/est/requestvoucher about 0123456789 [29] I, [2019-05-27T08:27:21.629067 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T08:27:21.629517 #1] INFO -- : Completed 500 Internal Server Error in 96ms (ActiveRecord: 78.2ms) I, [2019-05-27T08:28:58.398959 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 08:28:58 +0000 I, [2019-05-27T08:28:58.410463 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T08:28:58.412758 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T08:28:58.414910 #1] DEBUG -- : CmsVoucherRequest Create (0.6ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T08:28:58.000+00:00\",\"nonce\":\"7735981264354373\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 08:28:58.413140"], ["updated_at", "2019-05-27 08:28:58.413140"]] D, [2019-05-27T08:28:58.471441 #1] DEBUG -- : (56.0ms) COMMIT D, [2019-05-27T08:28:58.473367 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:28:58.474256 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:28:58.475693 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:28:58.476941 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:28:58.478385 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] I, [2019-05-27T08:28:58.478753 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T08:28:58.479172 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:28:58.481026 #1] DEBUG -- : CmsVoucherRequest Update (0.6ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 5], ["manufacturer_id", 1], ["device_identifier", "0123456789"], ["proxy_ip", "80.146.228.121"], ["nonce", "7735981264354373"], ["updated_at", "2019-05-27 08:28:58.479567"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIB2jCCAYCgAwIBAgIGAWegdcSLMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE4MTIxMjAzMjg1MVoYDzk5OTkxMjMxMjM1OTU5WjBSMQswCQYDVQQGEwJB\nUTEVMBMGA1UECgwMSmluZ0ppbmdDb3JwMRMwEQYDVQQFEwowMTIzNDU2Nzg5MRcw\nFQYDVQQDDA5KaW5nSmluZ0RldmljZTBZMBMGByqGSM49AgEGCCqGSM49AwEHA0IA\nBMVGG8Z5pjf5jXnyrUrXyZ1kPgqBe3NXu1dTADe+r/v6JzIHl355IgcHC3axpibq\nJM/bWRaEyjqcCJj4jJkowCujVTBTMCwGCSsGAQQBgu5SAgQfDB1tYXNhLXRlc3Qu\nc2llbWVucy1idC5uZXQ6OTQ0MzATBgNVHSUEDDAKBggrBgEFBQcDAjAOBgNVHQ8B\nAf8EBAMCB4AwCgYIKoZIzj0EAwIDSAAwRQIgWtPzIIXY2ixRXJtExKEhhZda4X+E\nplZomEI2zA0dsjoCIQC3JpQmRXMGn/p4Bu9izii92eclTx4/O4rlm7MyLqkhdA==\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1655 bytes of binary data>"], ["id", 30]] D, [2019-05-27T08:28:58.496429 #1] DEBUG -- : (14.9ms) COMMIT D, [2019-05-27T08:28:58.497501 #1] DEBUG -- : Device Load (0.4ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:28:58.498336 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:28:58.499635 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:28:58.500530 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:28:58.501602 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] D, [2019-05-27T08:28:58.502234 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:28:58.503176 #1] DEBUG -- : (0.2ms) COMMIT I, [2019-05-27T08:28:58.503423 #1] INFO -- : Contacting server at: https://masa-test.siemens-bt.net:9443/.well-known/est/requestvoucher about 0123456789 [30] I, [2019-05-27T08:28:58.503514 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T08:28:58.503944 #1] INFO -- : Completed 500 Internal Server Error in 93ms (ActiveRecord: 76.4ms) I, [2019-05-27T08:29:55.468113 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 08:29:55 +0000 I, [2019-05-27T08:29:55.479827 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T08:29:55.482129 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T08:29:55.484317 #1] DEBUG -- : CmsVoucherRequest Create (0.6ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T08:29:55.000+00:00\",\"nonce\":\"3088226265014559\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 08:29:55.482456"], ["updated_at", "2019-05-27 08:29:55.482456"]] D, [2019-05-27T08:29:55.494685 #1] DEBUG -- : (9.8ms) COMMIT D, [2019-05-27T08:29:55.496639 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:29:55.497524 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:29:55.498950 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:29:55.500194 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:29:55.501623 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] I, [2019-05-27T08:29:55.501936 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T08:29:55.502343 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:29:55.505001 #1] DEBUG -- : CmsVoucherRequest Update (1.2ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 5], ["manufacturer_id", 1], ["device_identifier", "0123456789"], ["proxy_ip", "80.146.228.121"], ["nonce", "3088226265014559"], ["updated_at", "2019-05-27 08:29:55.502782"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIB2jCCAYCgAwIBAgIGAWegdcSLMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE4MTIxMjAzMjg1MVoYDzk5OTkxMjMxMjM1OTU5WjBSMQswCQYDVQQGEwJB\nUTEVMBMGA1UECgwMSmluZ0ppbmdDb3JwMRMwEQYDVQQFEwowMTIzNDU2Nzg5MRcw\nFQYDVQQDDA5KaW5nSmluZ0RldmljZTBZMBMGByqGSM49AgEGCCqGSM49AwEHA0IA\nBMVGG8Z5pjf5jXnyrUrXyZ1kPgqBe3NXu1dTADe+r/v6JzIHl355IgcHC3axpibq\nJM/bWRaEyjqcCJj4jJkowCujVTBTMCwGCSsGAQQBgu5SAgQfDB1tYXNhLXRlc3Qu\nc2llbWVucy1idC5uZXQ6OTQ0MzATBgNVHSUEDDAKBggrBgEFBQcDAjAOBgNVHQ8B\nAf8EBAMCB4AwCgYIKoZIzj0EAwIDSAAwRQIgWtPzIIXY2ixRXJtExKEhhZda4X+E\nplZomEI2zA0dsjoCIQC3JpQmRXMGn/p4Bu9izii92eclTx4/O4rlm7MyLqkhdA==\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1656 bytes of binary data>"], ["id", 31]] D, [2019-05-27T08:29:55.528043 #1] DEBUG -- : (22.3ms) COMMIT D, [2019-05-27T08:29:55.529547 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:29:55.530512 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:29:55.531999 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:29:55.532947 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:29:55.534139 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] D, [2019-05-27T08:29:55.534800 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:29:55.535721 #1] DEBUG -- : (0.2ms) COMMIT I, [2019-05-27T08:29:55.535981 #1] INFO -- : Contacting server at: https://masa-test.siemens-bt.net:9443/.well-known/est/requestvoucher about 0123456789 [31] I, [2019-05-27T08:29:55.536057 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T08:29:55.536520 #1] INFO -- : Completed 500 Internal Server Error in 56ms (ActiveRecord: 38.4ms) I, [2019-05-27T08:30:44.224321 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 08:30:44 +0000 I, [2019-05-27T08:30:44.236123 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T08:30:44.238309 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T08:30:44.240481 #1] DEBUG -- : CmsVoucherRequest Create (0.6ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T08:30:44.000+00:00\",\"nonce\":\"2543287088854719\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 08:30:44.238680"], ["updated_at", "2019-05-27 08:30:44.238680"]] D, [2019-05-27T08:30:44.248694 #1] DEBUG -- : (7.7ms) COMMIT D, [2019-05-27T08:30:44.250707 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:30:44.251611 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:30:44.252999 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:30:44.254244 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:30:44.255767 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] I, [2019-05-27T08:30:44.256076 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T08:30:44.256467 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:30:44.258384 #1] DEBUG -- : CmsVoucherRequest Update (0.7ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 5], ["manufacturer_id", 1], ["device_identifier", "0123456789"], ["proxy_ip", "80.146.228.121"], ["nonce", "2543287088854719"], ["updated_at", "2019-05-27 08:30:44.256862"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIB2jCCAYCgAwIBAgIGAWegdcSLMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE4MTIxMjAzMjg1MVoYDzk5OTkxMjMxMjM1OTU5WjBSMQswCQYDVQQGEwJB\nUTEVMBMGA1UECgwMSmluZ0ppbmdDb3JwMRMwEQYDVQQFEwowMTIzNDU2Nzg5MRcw\nFQYDVQQDDA5KaW5nSmluZ0RldmljZTBZMBMGByqGSM49AgEGCCqGSM49AwEHA0IA\nBMVGG8Z5pjf5jXnyrUrXyZ1kPgqBe3NXu1dTADe+r/v6JzIHl355IgcHC3axpibq\nJM/bWRaEyjqcCJj4jJkowCujVTBTMCwGCSsGAQQBgu5SAgQfDB1tYXNhLXRlc3Qu\nc2llbWVucy1idC5uZXQ6OTQ0MzATBgNVHSUEDDAKBggrBgEFBQcDAjAOBgNVHQ8B\nAf8EBAMCB4AwCgYIKoZIzj0EAwIDSAAwRQIgWtPzIIXY2ixRXJtExKEhhZda4X+E\nplZomEI2zA0dsjoCIQC3JpQmRXMGn/p4Bu9izii92eclTx4/O4rlm7MyLqkhdA==\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1656 bytes of binary data>"], ["id", 32]] D, [2019-05-27T08:30:44.270970 #1] DEBUG -- : (12.1ms) COMMIT D, [2019-05-27T08:30:44.272149 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "0123456789"], ["LIMIT", 1]] D, [2019-05-27T08:30:44.272966 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:30:44.274225 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T08:30:44.275181 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://masa-test.siemens-bt.net:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T08:30:44.276300 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]] D, [2019-05-27T08:30:44.276927 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T08:30:44.277806 #1] DEBUG -- : (0.2ms) COMMIT I, [2019-05-27T08:30:44.278053 #1] INFO -- : Contacting server at: https://masa-test.siemens-bt.net:9443/.well-known/est/requestvoucher about 0123456789 [32] I, [2019-05-27T08:30:44.278128 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T08:30:44.278606 #1] INFO -- : Completed 500 Internal Server Error in 42ms (ActiveRecord: 25.2ms) I, [2019-05-27T09:21:47.713652 #1] INFO -- : Started GET "/status" for 80.146.228.121 at 2019-05-27 09:21:47 +0000 I, [2019-05-27T09:21:47.771755 #1] INFO -- : Processing by StatusController#index as HTML D, [2019-05-27T09:21:47.774679 #1] DEBUG -- : (2.0ms) SELECT COUNT(*) FROM "certificates" D, [2019-05-27T09:21:47.776197 #1] DEBUG -- : (1.0ms) SELECT COUNT(*) FROM "vouchers" D, [2019-05-27T09:21:47.778101 #1] DEBUG -- : (1.5ms) SELECT COUNT(*) FROM "voucher_requests" I, [2019-05-27T09:21:47.780872 #1] INFO -- : Rendering status/index.html.erb within layouts/reload I, [2019-05-27T09:21:47.781066 #1] INFO -- : Rendered status/index.html.erb within layouts/reload (0.1ms) I, [2019-05-27T09:21:47.781353 #1] INFO -- : Completed 200 OK in 9ms (Views: 2.8ms | ActiveRecord: 4.5ms) I, [2019-05-27T10:21:48.521053 #1] INFO -- : Started GET "/status" for 80.146.228.121 at 2019-05-27 10:21:48 +0000 I, [2019-05-27T10:21:48.532052 #1] INFO -- : Processing by StatusController#index as HTML D, [2019-05-27T10:21:48.533947 #1] DEBUG -- : (1.1ms) SELECT COUNT(*) FROM "certificates" D, [2019-05-27T10:21:48.534791 #1] DEBUG -- : (0.4ms) SELECT COUNT(*) FROM "vouchers" D, [2019-05-27T10:21:48.535576 #1] DEBUG -- : (0.4ms) SELECT COUNT(*) FROM "voucher_requests" I, [2019-05-27T10:21:48.537888 #1] INFO -- : Rendering status/index.html.erb within layouts/reload I, [2019-05-27T10:21:48.538065 #1] INFO -- : Rendered status/index.html.erb within layouts/reload (0.1ms) I, [2019-05-27T10:21:48.538309 #1] INFO -- : Completed 200 OK in 6ms (Views: 2.4ms | ActiveRecord: 1.9ms) I, [2019-05-27T11:20:46.831810 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 11:20:46 +0000 I, [2019-05-27T11:20:46.843051 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T11:20:46.845490 #1] DEBUG -- : (0.5ms) BEGIN D, [2019-05-27T11:20:46.848974 #1] DEBUG -- : CmsVoucherRequest Create (1.8ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T11:20:46.000+00:00\",\"nonce\":\"1384753024015266\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 11:20:46.845892"], ["updated_at", "2019-05-27 11:20:46.845892"]] D, [2019-05-27T11:20:46.872070 #1] DEBUG -- : (22.5ms) COMMIT D, [2019-05-27T11:20:46.876203 #1] DEBUG -- : Device Load (1.9ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:20:46.895952 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:20:46.898231 #1] DEBUG -- : Device Create (0.8ms) INSERT INTO "devices" ("eui64", "created_at", "updated_at", "traffic_counts") VALUES ($1, $2, $3, $4) RETURNING "id" [["eui64", "tw20190527"], ["created_at", "2019-05-27 11:20:46.896534"], ["updated_at", "2019-05-27 11:20:46.896534"], ["traffic_counts", "{\"packets\":[0,0],\"bytes\":[0,0]}"]] D, [2019-05-27T11:20:46.905171 #1] DEBUG -- : (6.4ms) COMMIT D, [2019-05-27T11:20:46.906729 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:20:46.908617 #1] DEBUG -- : Device Update (0.8ms) UPDATE "devices" SET "idevid" = $1, "updated_at" = $2, "idevid_hash" = $3 WHERE "devices"."id" = $4 [["idevid", "-----BEGIN CERTIFICATE-----\nMIIBtzCCAV6gAwIBAgIGAWr5A5uFMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE5MDUyNzExMTg0NFoYDzk5OTkxMjMxMjM1OTU5WjA1MQswCQYDVQQGEwJB\nUTETMBEGA1UEBRMKdHcyMDE5MDUyNzERMA8GA1UEAwwIcGxlZGdlVFcwWTATBgcq\nhkjOPQIBBggqhkjOPQMBBwNCAARVFdH7mc8xYnr/GZyZZLcNY7VCUDiL/MFiTScC\n1hlo2KkL5Bod+OvgjSIFdojbIzjkJc4AjFt+fhlrZ3ieeQJoo1AwTjAnBggrBgEF\nBQcBIAQbDBlmbG9yZWFuLnNhbmRlbG1hbi5jYTo5NDQzMBMGA1UdJQQMMAoGCCsG\nAQUFBwMCMA4GA1UdDwEB/wQEAwIHgDAKBggqhkjOPQQDAgNHADBEAiAM2fSjZ4xR\naP31p2HLQ89FffLUMiZHY5atO/56OyHDugIgIjzxZjwe2a4OfU8gd4Y+XOAlJM34\nkugGtrJzn9Tl9Sc=\n-----END CERTIFICATE-----\n"], ["updated_at", "2019-05-27 11:20:46.907083"], ["idevid_hash", "977986832a6f32a35f66ecceef914351f3dbd808529ebec6274ca4d769159c98"], ["id", 6]] D, [2019-05-27T11:20:46.916271 #1] DEBUG -- : (7.2ms) COMMIT D, [2019-05-27T11:20:46.918223 #1] DEBUG -- : Manufacturer Load (0.8ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:20:46.924586 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:20:46.926021 #1] DEBUG -- : Manufacturer Create (0.5ms) INSERT INTO "manufacturers" ("created_at", "updated_at", "masa_url", "issuer_dn") VALUES ($1, $2, $3, $4) RETURNING "id" [["created_at", "2019-05-27 11:20:46.924865"], ["updated_at", "2019-05-27 11:20:46.924865"], ["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:20:46.938486 #1] DEBUG -- : (12.1ms) COMMIT D, [2019-05-27T11:20:46.938981 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:20:46.940110 #1] DEBUG -- : Manufacturer Update (0.4ms) UPDATE "manufacturers" SET "name" = $1, "updated_at" = $2 WHERE "manufacturers"."id" = $3 [["name", "Manu5"], ["updated_at", "2019-05-27 11:20:46.939216"], ["id", 5]] D, [2019-05-27T11:20:46.949604 #1] DEBUG -- : (9.2ms) COMMIT D, [2019-05-27T11:20:46.950077 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:20:46.951885 #1] DEBUG -- : Device Update (0.6ms) UPDATE "devices" SET "manufacturer_id" = $1, "updated_at" = $2 WHERE "devices"."id" = $3 [["manufacturer_id", 5], ["updated_at", "2019-05-27 11:20:46.950470"], ["id", 6]] D, [2019-05-27T11:20:46.960717 #1] DEBUG -- : (8.4ms) COMMIT I, [2019-05-27T11:20:46.960883 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T11:20:46.961295 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:20:46.965286 #1] DEBUG -- : CmsVoucherRequest Update (2.8ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 6], ["manufacturer_id", 5], ["device_identifier", "tw20190527"], ["proxy_ip", "80.146.228.121"], ["nonce", "1384753024015266"], ["updated_at", "2019-05-27 11:20:46.961693"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIBtzCCAV6gAwIBAgIGAWr5A5uFMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE5MDUyNzExMTg0NFoYDzk5OTkxMjMxMjM1OTU5WjA1MQswCQYDVQQGEwJB\nUTETMBEGA1UEBRMKdHcyMDE5MDUyNzERMA8GA1UEAwwIcGxlZGdlVFcwWTATBgcq\nhkjOPQIBBggqhkjOPQMBBwNCAARVFdH7mc8xYnr/GZyZZLcNY7VCUDiL/MFiTScC\n1hlo2KkL5Bod+OvgjSIFdojbIzjkJc4AjFt+fhlrZ3ieeQJoo1AwTjAnBggrBgEF\nBQcBIAQbDBlmbG9yZWFuLnNhbmRlbG1hbi5jYTo5NDQzMBMGA1UdJQQMMAoGCCsG\nAQUFBwMCMA4GA1UdDwEB/wQEAwIHgDAKBggqhkjOPQQDAgNHADBEAiAM2fSjZ4xR\naP31p2HLQ89FffLUMiZHY5atO/56OyHDugIgIjzxZjwe2a4OfU8gd4Y+XOAlJM34\nkugGtrJzn9Tl9Sc=\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1621 bytes of binary data>"], ["id", 33]] D, [2019-05-27T11:20:46.982993 #1] DEBUG -- : (17.2ms) COMMIT D, [2019-05-27T11:20:46.984333 #1] DEBUG -- : Device Load (0.6ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:20:46.985189 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:20:46.986509 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T11:20:46.987456 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:20:46.988866 #1] DEBUG -- : Manufacturer Load (0.3ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] D, [2019-05-27T11:20:46.989489 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:20:46.990247 #1] DEBUG -- : (0.2ms) COMMIT I, [2019-05-27T11:20:46.990489 #1] INFO -- : Contacting server at: https://florean.sandelman.ca:9443/.well-known/est/requestvoucher about tw20190527 [33] I, [2019-05-27T11:20:46.990563 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T11:20:46.991082 #1] INFO -- : Completed 500 Internal Server Error in 148ms (ActiveRecord: 120.3ms) I, [2019-05-27T11:20:52.077256 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 11:20:52 +0000 I, [2019-05-27T11:20:52.136165 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T11:20:52.138553 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T11:20:52.143525 #1] DEBUG -- : CmsVoucherRequest Create (3.3ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T11:20:51.000+00:00\",\"nonce\":\"0628131806065283\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 11:20:52.138971"], ["updated_at", "2019-05-27 11:20:52.138971"]] D, [2019-05-27T11:20:52.160865 #1] DEBUG -- : (16.8ms) COMMIT D, [2019-05-27T11:20:52.165129 #1] DEBUG -- : Device Load (2.0ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:20:52.186484 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T11:20:52.188118 #1] DEBUG -- : (0.3ms) COMMIT D, [2019-05-27T11:20:52.190054 #1] DEBUG -- : Manufacturer Load (0.8ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:20:52.197849 #1] DEBUG -- : Manufacturer Load (0.3ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] I, [2019-05-27T11:20:52.198166 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T11:20:52.198682 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T11:20:52.202270 #1] DEBUG -- : CmsVoucherRequest Update (2.2ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 6], ["manufacturer_id", 5], ["device_identifier", "tw20190527"], ["proxy_ip", "80.146.228.121"], ["nonce", "0628131806065283"], ["updated_at", "2019-05-27 11:20:52.199116"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIBtzCCAV6gAwIBAgIGAWr5A5uFMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE5MDUyNzExMTg0NFoYDzk5OTkxMjMxMjM1OTU5WjA1MQswCQYDVQQGEwJB\nUTETMBEGA1UEBRMKdHcyMDE5MDUyNzERMA8GA1UEAwwIcGxlZGdlVFcwWTATBgcq\nhkjOPQIBBggqhkjOPQMBBwNCAARVFdH7mc8xYnr/GZyZZLcNY7VCUDiL/MFiTScC\n1hlo2KkL5Bod+OvgjSIFdojbIzjkJc4AjFt+fhlrZ3ieeQJoo1AwTjAnBggrBgEF\nBQcBIAQbDBlmbG9yZWFuLnNhbmRlbG1hbi5jYTo5NDQzMBMGA1UdJQQMMAoGCCsG\nAQUFBwMCMA4GA1UdDwEB/wQEAwIHgDAKBggqhkjOPQQDAgNHADBEAiAM2fSjZ4xR\naP31p2HLQ89FffLUMiZHY5atO/56OyHDugIgIjzxZjwe2a4OfU8gd4Y+XOAlJM34\nkugGtrJzn9Tl9Sc=\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1621 bytes of binary data>"], ["id", 34]] D, [2019-05-27T11:20:52.216172 #1] DEBUG -- : (13.3ms) COMMIT D, [2019-05-27T11:20:52.217381 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:20:52.218276 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:20:52.219761 #1] DEBUG -- : (0.3ms) COMMIT D, [2019-05-27T11:20:52.220743 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:20:52.221922 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] D, [2019-05-27T11:20:52.222763 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T11:20:52.223858 #1] DEBUG -- : (0.2ms) COMMIT I, [2019-05-27T11:20:52.224106 #1] INFO -- : Contacting server at: https://florean.sandelman.ca:9443/.well-known/est/requestvoucher about tw20190527 [34] I, [2019-05-27T11:20:52.224181 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T11:20:52.224614 #1] INFO -- : Completed 500 Internal Server Error in 88ms (ActiveRecord: 65.3ms) I, [2019-05-27T11:21:24.560272 #1] INFO -- : Started GET "/status" for 80.146.228.121 at 2019-05-27 11:21:24 +0000 I, [2019-05-27T11:21:24.572699 #1] INFO -- : Processing by StatusController#index as HTML D, [2019-05-27T11:21:24.575170 #1] DEBUG -- : (1.5ms) SELECT COUNT(*) FROM "certificates" D, [2019-05-27T11:21:24.576493 #1] DEBUG -- : (0.8ms) SELECT COUNT(*) FROM "vouchers" D, [2019-05-27T11:21:24.577541 #1] DEBUG -- : (0.6ms) SELECT COUNT(*) FROM "voucher_requests" I, [2019-05-27T11:21:24.580096 #1] INFO -- : Rendering status/index.html.erb within layouts/reload I, [2019-05-27T11:21:24.580290 #1] INFO -- : Rendered status/index.html.erb within layouts/reload (0.1ms) I, [2019-05-27T11:21:24.580540 #1] INFO -- : Completed 200 OK in 8ms (Views: 2.6ms | ActiveRecord: 2.9ms) I, [2019-05-27T11:21:45.398433 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 11:21:45 +0000 I, [2019-05-27T11:21:45.410061 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T11:21:45.413116 #1] DEBUG -- : (0.4ms) BEGIN D, [2019-05-27T11:21:45.415884 #1] DEBUG -- : CmsVoucherRequest Create (0.7ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T11:21:45.000+00:00\",\"nonce\":\"9325294111955459\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 11:21:45.413557"], ["updated_at", "2019-05-27 11:21:45.413557"]] D, [2019-05-27T11:21:45.426238 #1] DEBUG -- : (9.7ms) COMMIT D, [2019-05-27T11:21:45.428499 #1] DEBUG -- : Device Load (0.6ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:21:45.429389 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:21:45.431239 #1] DEBUG -- : (0.3ms) COMMIT D, [2019-05-27T11:21:45.432666 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:21:45.434390 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] I, [2019-05-27T11:21:45.434837 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T11:21:45.435234 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:21:45.438260 #1] DEBUG -- : CmsVoucherRequest Update (1.5ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 6], ["manufacturer_id", 5], ["device_identifier", "tw20190527"], ["proxy_ip", "80.146.228.121"], ["nonce", "9325294111955459"], ["updated_at", "2019-05-27 11:21:45.435739"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIBtzCCAV6gAwIBAgIGAWr5A5uFMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE5MDUyNzExMTg0NFoYDzk5OTkxMjMxMjM1OTU5WjA1MQswCQYDVQQGEwJB\nUTETMBEGA1UEBRMKdHcyMDE5MDUyNzERMA8GA1UEAwwIcGxlZGdlVFcwWTATBgcq\nhkjOPQIBBggqhkjOPQMBBwNCAARVFdH7mc8xYnr/GZyZZLcNY7VCUDiL/MFiTScC\n1hlo2KkL5Bod+OvgjSIFdojbIzjkJc4AjFt+fhlrZ3ieeQJoo1AwTjAnBggrBgEF\nBQcBIAQbDBlmbG9yZWFuLnNhbmRlbG1hbi5jYTo5NDQzMBMGA1UdJQQMMAoGCCsG\nAQUFBwMCMA4GA1UdDwEB/wQEAwIHgDAKBggqhkjOPQQDAgNHADBEAiAM2fSjZ4xR\naP31p2HLQ89FffLUMiZHY5atO/56OyHDugIgIjzxZjwe2a4OfU8gd4Y+XOAlJM34\nkugGtrJzn9Tl9Sc=\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1621 bytes of binary data>"], ["id", 35]] D, [2019-05-27T11:21:45.459060 #1] DEBUG -- : (19.8ms) COMMIT D, [2019-05-27T11:21:45.461121 #1] DEBUG -- : Device Load (0.6ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:21:45.462158 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:21:45.464098 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T11:21:45.465300 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:21:45.466629 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] D, [2019-05-27T11:21:45.467483 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:21:45.468584 #1] DEBUG -- : (0.3ms) COMMIT I, [2019-05-27T11:21:45.468836 #1] INFO -- : Contacting server at: https://florean.sandelman.ca:9443/.well-known/est/requestvoucher about tw20190527 [35] I, [2019-05-27T11:21:45.468910 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T11:21:45.469618 #1] INFO -- : Completed 500 Internal Server Error in 59ms (ActiveRecord: 36.7ms) I, [2019-05-27T11:21:57.849832 #1] INFO -- : Started GET "/status" for 80.146.228.121 at 2019-05-27 11:21:57 +0000 I, [2019-05-27T11:21:57.863423 #1] INFO -- : Processing by StatusController#index as HTML D, [2019-05-27T11:21:57.865043 #1] DEBUG -- : (0.5ms) SELECT COUNT(*) FROM "certificates" D, [2019-05-27T11:21:57.865938 #1] DEBUG -- : (0.4ms) SELECT COUNT(*) FROM "vouchers" D, [2019-05-27T11:21:57.866943 #1] DEBUG -- : (0.6ms) SELECT COUNT(*) FROM "voucher_requests" I, [2019-05-27T11:21:57.869628 #1] INFO -- : Rendering status/index.html.erb within layouts/reload I, [2019-05-27T11:21:57.869901 #1] INFO -- : Rendered status/index.html.erb within layouts/reload (0.2ms) I, [2019-05-27T11:21:57.870143 #1] INFO -- : Completed 200 OK in 7ms (Views: 2.8ms | ActiveRecord: 1.5ms) I, [2019-05-27T11:25:13.911239 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 11:25:13 +0000 I, [2019-05-27T11:25:13.923844 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T11:25:13.927174 #1] DEBUG -- : (0.4ms) BEGIN D, [2019-05-27T11:25:13.929973 #1] DEBUG -- : CmsVoucherRequest Create (0.7ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T11:25:13.000+00:00\",\"nonce\":\"0990590686396138\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 11:25:13.927528"], ["updated_at", "2019-05-27 11:25:13.927528"]] D, [2019-05-27T11:25:13.939965 #1] DEBUG -- : (9.3ms) COMMIT D, [2019-05-27T11:25:13.942769 #1] DEBUG -- : Device Load (0.6ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:25:13.943842 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:25:13.945807 #1] DEBUG -- : (0.3ms) COMMIT D, [2019-05-27T11:25:13.947332 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:25:13.948999 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] I, [2019-05-27T11:25:13.949420 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T11:25:13.949817 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:25:13.953037 #1] DEBUG -- : CmsVoucherRequest Update (1.6ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 6], ["manufacturer_id", 5], ["device_identifier", "tw20190527"], ["proxy_ip", "80.146.228.121"], ["nonce", "0990590686396138"], ["updated_at", "2019-05-27 11:25:13.950224"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIBtzCCAV6gAwIBAgIGAWr5A5uFMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE5MDUyNzExMTg0NFoYDzk5OTkxMjMxMjM1OTU5WjA1MQswCQYDVQQGEwJB\nUTETMBEGA1UEBRMKdHcyMDE5MDUyNzERMA8GA1UEAwwIcGxlZGdlVFcwWTATBgcq\nhkjOPQIBBggqhkjOPQMBBwNCAARVFdH7mc8xYnr/GZyZZLcNY7VCUDiL/MFiTScC\n1hlo2KkL5Bod+OvgjSIFdojbIzjkJc4AjFt+fhlrZ3ieeQJoo1AwTjAnBggrBgEF\nBQcBIAQbDBlmbG9yZWFuLnNhbmRlbG1hbi5jYTo5NDQzMBMGA1UdJQQMMAoGCCsG\nAQUFBwMCMA4GA1UdDwEB/wQEAwIHgDAKBggqhkjOPQQDAgNHADBEAiAM2fSjZ4xR\naP31p2HLQ89FffLUMiZHY5atO/56OyHDugIgIjzxZjwe2a4OfU8gd4Y+XOAlJM34\nkugGtrJzn9Tl9Sc=\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1621 bytes of binary data>"], ["id", 36]] D, [2019-05-27T11:25:13.973031 #1] DEBUG -- : (19.3ms) COMMIT D, [2019-05-27T11:25:13.974398 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:25:13.975371 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:25:13.976958 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T11:25:13.978086 #1] DEBUG -- : Manufacturer Load (0.5ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:25:13.979456 #1] DEBUG -- : Manufacturer Load (0.5ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] D, [2019-05-27T11:25:13.980203 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:25:13.981246 #1] DEBUG -- : (0.3ms) COMMIT I, [2019-05-27T11:25:13.981508 #1] INFO -- : Contacting server at: https://florean.sandelman.ca:9443/.well-known/est/requestvoucher about tw20190527 [36] I, [2019-05-27T11:25:13.981583 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T11:25:13.982200 #1] INFO -- : Completed 500 Internal Server Error in 58ms (ActiveRecord: 35.7ms) I, [2019-05-27T11:28:38.524510 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 11:28:38 +0000 I, [2019-05-27T11:28:38.536827 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T11:28:38.539177 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T11:28:38.541422 #1] DEBUG -- : CmsVoucherRequest Create (0.6ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T11:28:38.000+00:00\",\"nonce\":\"8770804466086808\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 11:28:38.539508"], ["updated_at", "2019-05-27 11:28:38.539508"]] D, [2019-05-27T11:28:38.605350 #1] DEBUG -- : (63.2ms) COMMIT D, [2019-05-27T11:28:38.607433 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:28:38.608451 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:28:38.610183 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T11:28:38.611556 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:28:38.613223 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] I, [2019-05-27T11:28:38.613636 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T11:28:38.614048 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:28:38.616403 #1] DEBUG -- : CmsVoucherRequest Update (0.9ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 6], ["manufacturer_id", 5], ["device_identifier", "tw20190527"], ["proxy_ip", "80.146.228.121"], ["nonce", "8770804466086808"], ["updated_at", "2019-05-27 11:28:38.614433"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIBtzCCAV6gAwIBAgIGAWr5A5uFMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE5MDUyNzExMTg0NFoYDzk5OTkxMjMxMjM1OTU5WjA1MQswCQYDVQQGEwJB\nUTETMBEGA1UEBRMKdHcyMDE5MDUyNzERMA8GA1UEAwwIcGxlZGdlVFcwWTATBgcq\nhkjOPQIBBggqhkjOPQMBBwNCAARVFdH7mc8xYnr/GZyZZLcNY7VCUDiL/MFiTScC\n1hlo2KkL5Bod+OvgjSIFdojbIzjkJc4AjFt+fhlrZ3ieeQJoo1AwTjAnBggrBgEF\nBQcBIAQbDBlmbG9yZWFuLnNhbmRlbG1hbi5jYTo5NDQzMBMGA1UdJQQMMAoGCCsG\nAQUFBwMCMA4GA1UdDwEB/wQEAwIHgDAKBggqhkjOPQQDAgNHADBEAiAM2fSjZ4xR\naP31p2HLQ89FffLUMiZHY5atO/56OyHDugIgIjzxZjwe2a4OfU8gd4Y+XOAlJM34\nkugGtrJzn9Tl9Sc=\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1621 bytes of binary data>"], ["id", 37]] D, [2019-05-27T11:28:38.630795 #1] DEBUG -- : (13.8ms) COMMIT D, [2019-05-27T11:28:38.631895 #1] DEBUG -- : Device Load (0.4ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:28:38.632816 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:28:38.634370 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T11:28:38.635410 #1] DEBUG -- : Manufacturer Load (0.5ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:28:38.636735 #1] DEBUG -- : Manufacturer Load (0.5ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] D, [2019-05-27T11:28:38.637378 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:28:38.638381 #1] DEBUG -- : (0.2ms) COMMIT I, [2019-05-27T11:28:38.638666 #1] INFO -- : Contacting server at: https://florean.sandelman.ca:9443/.well-known/est/requestvoucher about tw20190527 [37] I, [2019-05-27T11:28:38.638743 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T11:28:38.639276 #1] INFO -- : Completed 500 Internal Server Error in 102ms (ActiveRecord: 83.1ms) I, [2019-05-27T11:32:11.005540 #1] INFO -- : Started POST "/.well-known/est/requestvoucher" for 80.146.228.121 at 2019-05-27 11:32:11 +0000 I, [2019-05-27T11:32:11.018365 #1] INFO -- : Processing by EstController#requestvoucher as D, [2019-05-27T11:32:11.021468 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T11:32:11.024173 #1] DEBUG -- : CmsVoucherRequest Create (0.7ms) INSERT INTO "voucher_requests" ("details", "signed", "created_at", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" [["details", "{\"ietf-voucher-request:voucher\":{\"created-on\":\"2019-05-27T11:32:10.000+00:00\",\"nonce\":\"8384415915097500\",\"assertion\":\"proximity\",\"proximity-registrar-cert\":\"MIIB4TCCAWegAwIBAgIEIelRdDAKBggqhkjOPQQDAjBnMRIwEAYKCZImiZPyLGQBGRYCY2ExGTAXBgoJkiaJk/IsZAEZFglzYW5kZWxtYW4xNjA0BgNVBAMMLWdhbWJvbC5zYW5kZWxtYW4uY2EgVW5zdHJ1bmcgRm91bnRhaW4gUm9vdCBDQTAeFw0xOTA1MjMxNDI0NTZaFw0xOTA2MjMwMDI0NTZaME0xEjAQBgoJkiaJk/IsZAEZFgJjYTEZMBcGCgmSJomT8ixkARkWCXNhbmRlbG1hbjEcMBoGA1UEAwwTZ2FtYm9sLnNhbmRlbG1hbi5jYTB2MBAGByqGSM49AgEGBSuBBAAiA2IABPFxkHMee281cmlzpMuTdf7c0fEg1Xq+hQkbLCeWsmq+Td4YY1W3zU4anG4B7VpOYlS2Ur43yQ5g6dAKjZoKn3TQOnW4iAd52SKYJo55WyzlMXfS9FTZMN7vQv7ZZ6ksYTAKBggqhkjOPQQDAgNoADBlAjEApFMVvvvcRF1phiSmIkxspUSQM1nNHK81Leke2npUNPI+eBU1aXNmgASCZvh93UzcAjBdhIpvUzYpuARIVjdvTjaRMjaqTG9dn0gmDpV1huBRF6uk9SJF9kthQqHMXWXfZos=\"}}"], ["signed", true], ["created_at", "2019-05-27 11:32:11.021806"], ["updated_at", "2019-05-27 11:32:11.021806"]] D, [2019-05-27T11:32:11.085704 #1] DEBUG -- : (60.8ms) COMMIT D, [2019-05-27T11:32:11.088093 #1] DEBUG -- : Device Load (0.6ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:32:11.089115 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:32:11.090870 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T11:32:11.092351 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:32:11.094084 #1] DEBUG -- : Manufacturer Load (0.4ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] I, [2019-05-27T11:32:11.094512 #1] INFO -- : voucher request from 80.146.228.121 D, [2019-05-27T11:32:11.094925 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:32:11.097092 #1] DEBUG -- : CmsVoucherRequest Update (0.8ms) UPDATE "voucher_requests" SET "device_id" = $1, "manufacturer_id" = $2, "device_identifier" = $3, "proxy_ip" = $4, "nonce" = $5, "updated_at" = $6, "tls_clientcert" = $7, "pledge_request" = $8 WHERE "voucher_requests"."id" = $9 [["device_id", 6], ["manufacturer_id", 5], ["device_identifier", "tw20190527"], ["proxy_ip", "80.146.228.121"], ["nonce", "8384415915097500"], ["updated_at", "2019-05-27 11:32:11.095316"], ["tls_clientcert", "-----BEGIN CERTIFICATE-----\nMIIBtzCCAV6gAwIBAgIGAWr5A5uFMAoGCCqGSM49BAMCMD0xCzAJBgNVBAYTAkFR\nMRUwEwYDVQQKDAxKaW5nSmluZ0NvcnAxFzAVBgNVBAMMDkppbmdKaW5nVGVzdENB\nMCAXDTE5MDUyNzExMTg0NFoYDzk5OTkxMjMxMjM1OTU5WjA1MQswCQYDVQQGEwJB\nUTETMBEGA1UEBRMKdHcyMDE5MDUyNzERMA8GA1UEAwwIcGxlZGdlVFcwWTATBgcq\nhkjOPQIBBggqhkjOPQMBBwNCAARVFdH7mc8xYnr/GZyZZLcNY7VCUDiL/MFiTScC\n1hlo2KkL5Bod+OvgjSIFdojbIzjkJc4AjFt+fhlrZ3ieeQJoo1AwTjAnBggrBgEF\nBQcBIAQbDBlmbG9yZWFuLnNhbmRlbG1hbi5jYTo5NDQzMBMGA1UdJQQMMAoGCCsG\nAQUFBwMCMA4GA1UdDwEB/wQEAwIHgDAKBggqhkjOPQQDAgNHADBEAiAM2fSjZ4xR\naP31p2HLQ89FffLUMiZHY5atO/56OyHDugIgIjzxZjwe2a4OfU8gd4Y+XOAlJM34\nkugGtrJzn9Tl9Sc=\n-----END CERTIFICATE-----\n"], ["pledge_request", "<1621 bytes of binary data>"], ["id", 38]] D, [2019-05-27T11:32:11.111288 #1] DEBUG -- : (13.5ms) COMMIT D, [2019-05-27T11:32:11.112665 #1] DEBUG -- : Device Load (0.5ms) SELECT "devices".* FROM "devices" WHERE "devices"."eui64" = $1 LIMIT $2 [["eui64", "tw20190527"], ["LIMIT", 1]] D, [2019-05-27T11:32:11.113595 #1] DEBUG -- : (0.2ms) BEGIN D, [2019-05-27T11:32:11.115317 #1] DEBUG -- : (0.2ms) COMMIT D, [2019-05-27T11:32:11.116460 #1] DEBUG -- : Manufacturer Load (0.5ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."masa_url" = $1 AND "manufacturers"."issuer_dn" = $2 [["masa_url", "https://florean.sandelman.ca:9443/.well-known/est/"], ["issuer_dn", "/C=AQ/O=JingJingCorp/CN=JingJingTestCA"]] D, [2019-05-27T11:32:11.117686 #1] DEBUG -- : Manufacturer Load (0.5ms) SELECT "manufacturers".* FROM "manufacturers" WHERE "manufacturers"."id" = $1 LIMIT $2 [["id", 5], ["LIMIT", 1]] D, [2019-05-27T11:32:11.118419 #1] DEBUG -- : (0.3ms) BEGIN D, [2019-05-27T11:32:11.119511 #1] DEBUG -- : (0.3ms) COMMIT I, [2019-05-27T11:32:11.119774 #1] INFO -- : Contacting server at: https://florean.sandelman.ca:9443/.well-known/est/requestvoucher about tw20190527 [38] I, [2019-05-27T11:32:11.119848 #1] INFO -- : Asking for voucher of type: application/voucher-cms+json I, [2019-05-27T11:32:11.120576 #1] INFO -- : Completed 500 Internal Server Error in 102ms (ActiveRecord: 80.5ms) I, [2019-05-27T12:21:58.638288 #1] INFO -- : Started GET "/status" for 80.146.228.121 at 2019-05-27 12:21:58 +0000 I, [2019-05-27T12:21:58.699737 #1] INFO -- : Processing by StatusController#index as HTML D, [2019-05-27T12:21:58.702708 #1] DEBUG -- : (2.0ms) SELECT COUNT(*) FROM "certificates" D, [2019-05-27T12:21:58.704307 #1] DEBUG -- : (1.0ms) SELECT COUNT(*) FROM "vouchers" D, [2019-05-27T12:21:58.706391 #1] DEBUG -- : (1.7ms) SELECT COUNT(*) FROM "voucher_requests" I, [2019-05-27T12:21:58.709006 #1] INFO -- : Rendering status/index.html.erb within layouts/reload I, [2019-05-27T12:21:58.709195 #1] INFO -- : Rendered status/index.html.erb within layouts/reload (0.1ms) I, [2019-05-27T12:21:58.709437 #1] INFO -- : Completed 200 OK in 9ms (Views: 2.6ms | ActiveRecord: 4.7ms) I, [2019-05-27T13:21:59.612759 #1] INFO -- : Started GET "/status" for 80.146.228.121 at 2019-05-27 13:21:59 +0000 I, [2019-05-27T13:21:59.625196 #1] INFO -- : Processing by StatusController#index as HTML D, [2019-05-27T13:21:59.626996 #1] DEBUG -- : (1.0ms) SELECT COUNT(*) FROM "certificates" D, [2019-05-27T13:21:59.628067 #1] DEBUG -- : (0.5ms) SELECT COUNT(*) FROM "vouchers" D, [2019-05-27T13:21:59.628851 #1] DEBUG -- : (0.4ms) SELECT COUNT(*) FROM "voucher_requests" I, [2019-05-27T13:21:59.631501 #1] INFO -- : Rendering status/index.html.erb within layouts/reload I, [2019-05-27T13:21:59.631788 #1] INFO -- : Rendered status/index.html.erb within layouts/reload (0.2ms) I, [2019-05-27T13:21:59.632053 #1] INFO -- : Completed 200 OK in 7ms (Views: 2.7ms | ActiveRecord: 2.0ms)