cmsis-pack-manager icon indicating copy to clipboard operation
cmsis-pack-manager copied to clipboard

cmsis-pack-manager fails to download some CMSIS-packs

Open JanneKiiskila opened this issue 6 years ago • 54 comments

If you try to update the cmsis packs in Mbed OS with python project.py -m STM32F7xx --update-packs it will start downloading the pack files.

For a few ST packs, you will get the following error note:

Oct 02 18:34:25.840 ERRO download of "https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc" failed: unexpected end of file
Oct 02 18:34:25.840 ERRO download of "https://www.keil.com/pack/Keil.STM32H7xx_DFP.pdsc" failed: unexpected end of file
Oct 02 18:34:25.840 ERRO download of "https://www.keil.com/pack/Keil.STM32G0xx_DFP.pdsc" failed: unexpected end of file

(Edit: removed the faulty analysis of any redirects, title updated, too).

JanneKiiskila avatar Oct 03 '19 07:10 JanneKiiskila

Nope. We support redirects. All of the keil.com pdcs redirect. These are not special. And we download the others. Perhaps they do not use a 300 for the redirect.


The linked code does not implement downloading, it calls the actual download function across a stream of files. What does futures::Stream have to do with all of this?

theotherjimmy avatar Oct 03 '19 12:10 theotherjimmy

They give a 302.

<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head><script type="text/javascript">window.NREUM||(NREUM={});NREUM.info = {"beacon":"bam.nr-data.net","errorBeacon":"bam.nr-data.net","licenseKey":"c4afc5d5b0","applicationID":"38150566","transactionName":"Y1FVbUUFDBAAU0xeXVobZE1WEBcQIl9cUh0HBAU=","queueTime":0,"applicationTime":1,"ttGuid":"ED76BAEBF58981FC","agent":""}</script><script type="text/javascript">window.NREUM||(NREUM={}),__nr_require=function(e,n,t){function r(t){if(!n[t]){var o=n[t]={exports:{}};e[t][0].call(o.exports,function(n){var o=e[t][1][n];return r(o||n)},o,o.exports)}return n[t].exports}if("function"==typeof __nr_require)return __nr_require;for(var o=0;o<t.length;o++)r(t[o]);return r}({1:[function(e,n,t){function r(){}function o(e,n,t){return function(){return i(e,[c.now()].concat(u(arguments)),n?null:this,t),n?void 0:this}}var i=e("handle"),a=e(3),u=e(4),f=e("ee").get("tracer"),c=e("loader"),s=NREUM;"undefined"==typeof window.newrelic&&(newrelic=s);var p=["setPageViewName","setCustomAttribute","setErrorHandler","finished","addToTrace","inlineHit","addRelease"],d="api-",l=d+"ixn-";a(p,function(e,n){s[n]=o(d+n,!0,"api")}),s.addPageAction=o(d+"addPageAction",!0),s.setCurrentRouteName=o(d+"routeName",!0),n.exports=newrelic,s.interaction=function(){return(new r).get()};var m=r.prototype={createTracer:function(e,n){var t={},r=this,o="function"==typeof n;return i(l+"tracer",[c.now(),e,t],r),function(){if(f.emit((o?"":"no-")+"fn-start",[c.now(),r,o],t),o)try{return n.apply(this,arguments)}catch(e){throw f.emit("fn-err",[arguments,this,e],t),e}finally{f.emit("fn-end",[c.now()],t)}}}};a("actionText,setName,setAttribute,save,ignore,onEnd,getContext,end,get".split(","),function(e,n){m[n]=o(l+n)}),newrelic.noticeError=function(e,n){"string"==typeof e&&(e=new Error(e)),i("err",[e,c.now(),!1,n])}},{}],2:[function(e,n,t){function r(e,n){if(!o)return!1;if(e!==o)return!1;if(!n)return!0;if(!i)return!1;for(var t=i.split("."),r=n.split("."),a=0;a<r.length;a++)if(r[a]!==t[a])return!1;return!0}var o=null,i=null,a=/Version\/(\S+)\s+Safari/;if(navigator.userAgent){var u=navigator.userAgent,f=u.match(a);f&&u.indexOf("Chrome")===-1&&u.indexOf("Chromium")===-1&&(o="Safari",i=f[1])}n.exports={agent:o,version:i,match:r}},{}],3:[function(e,n,t){function r(e,n){var t=[],r="",i=0;for(r in e)o.call(e,r)&&(t[i]=n(r,e[r]),i+=1);return t}var o=Object.prototype.hasOwnProperty;n.exports=r},{}],4:[function(e,n,t){function r(e,n,t){n||(n=0),"undefined"==typeof t&&(t=e?e.length:0);for(var r=-1,o=t-n||0,i=Array(o<0?0:o);++r<o;)i[r]=e[n+r];return i}n.exports=r},{}],5:[function(e,n,t){n.exports={exists:"undefined"!=typeof window.performance&&window.performance.timing&&"undefined"!=typeof window.performance.timing.navigationStart}},{}],ee:[function(e,n,t){function r(){}function o(e){function n(e){return e&&e instanceof r?e:e?f(e,u,i):i()}function t(t,r,o,i){if(!d.aborted||i){e&&e(t,r,o);for(var a=n(o),u=v(t),f=u.length,c=0;c<f;c++)u[c].apply(a,r);var p=s[y[t]];return p&&p.push([b,t,r,a]),a}}function l(e,n){h[e]=v(e).concat(n)}function m(e,n){var t=h[e];if(t)for(var r=0;r<t.length;r++)t[r]===n&&t.splice(r,1)}function v(e){return h[e]||[]}function g(e){return p[e]=p[e]||o(t)}function w(e,n){c(e,function(e,t){n=n||"feature",y[t]=n,n in s||(s[n]=[])})}var h={},y={},b={on:l,addEventListener:l,removeEventListener:m,emit:t,get:g,listeners:v,context:n,buffer:w,abort:a,aborted:!1};return b}function i(){return new r}function a(){(s.api||s.feature)&&(d.aborted=!0,s=d.backlog={})}var u="nr@context",f=e("gos"),c=e(3),s={},p={},d=n.exports=o();d.backlog=s},{}],gos:[function(e,n,t){function r(e,n,t){if(o.call(e,n))return e[n];var r=t();if(Object.defineProperty&&Object.keys)try{return Object.defineProperty(e,n,{value:r,writable:!0,enumerable:!1}),r}catch(i){}return e[n]=r,r}var o=Object.prototype.hasOwnProperty;n.exports=r},{}],handle:[function(e,n,t){function r(e,n,t,r){o.buffer([e],r),o.emit(e,n,t)}var o=e("ee").get("handle");n.exports=r,r.ee=o},{}],id:[function(e,n,t){function r(e){var n=typeof e;return!e||"object"!==n&&"function"!==n?-1:e===window?0:a(e,i,function(){return o++})}var o=1,i="nr@id",a=e("gos");n.exports=r},{}],loader:[function(e,n,t){function r(){if(!E++){var e=x.info=NREUM.info,n=l.getElementsByTagName("script")[0];if(setTimeout(s.abort,3e4),!(e&&e.licenseKey&&e.applicationID&&n))return s.abort();c(y,function(n,t){e[n]||(e[n]=t)}),f("mark",["onload",a()+x.offset],null,"api");var t=l.createElement("script");t.src="https://"+e.agent,n.parentNode.insertBefore(t,n)}}function o(){"complete"===l.readyState&&i()}function i(){f("mark",["domContent",a()+x.offset],null,"api")}function a(){return O.exists&&performance.now?Math.round(performance.now()):(u=Math.max((new Date).getTime(),u))-x.offset}var u=(new Date).getTime(),f=e("handle"),c=e(3),s=e("ee"),p=e(2),d=window,l=d.document,m="addEventListener",v="attachEvent",g=d.XMLHttpRequest,w=g&&g.prototype;NREUM.o={ST:setTimeout,SI:d.setImmediate,CT:clearTimeout,XHR:g,REQ:d.Request,EV:d.Event,PR:d.Promise,MO:d.MutationObserver};var h=""+location,y={beacon:"bam.nr-data.net",errorBeacon:"bam.nr-data.net",agent:"js-agent.newrelic.com/nr-1130.min.js"},b=g&&w&&w[m]&&!/CriOS/.test(navigator.userAgent),x=n.exports={offset:u,now:a,origin:h,features:{},xhrWrappable:b,userAgent:p};e(1),l[m]?(l[m]("DOMContentLoaded",i,!1),d[m]("load",r,!1)):(l[v]("onreadystatechange",o),d[v]("onload",r)),f("mark",["firstbyte",u],null,"api");var E=0,O=e(5)},{}]},{},["loader"]);</script>
<title>302 Found</title>
</head><body>
<h1>Found</h1><p>The document has moved <a href="http://sadevicepacksprodus.blob.core.windows.net/pdsc/Keil.STM32F7xx_DFP.pdsc">here</a>.</p>

Well, actually they give likely just 200 OK as the error code and then a page with <a href>.

JanneKiiskila avatar Oct 03 '19 13:10 JanneKiiskila

Well, actually they give likely just 200 OK as the error code and then a page with .

That sounds like a 200. Also, that's a lot of javascript.

theotherjimmy avatar Oct 03 '19 13:10 theotherjimmy

Yeah, it's actually really hard to write a command line tool that takes a 200 OK and realizes that it's actually a redirect. Also note that the error might have nothing to do with this, as it's about the file ending too soon.

theotherjimmy avatar Oct 03 '19 13:10 theotherjimmy

❯❯ curl https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc -D header
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head><script type="text/javascript">window.NREUM||(NREUM={});NREUM.info = {"beacon":"bam.nr-data.net","errorBeacon":"bam.nr-data.net","licenseKey":"c4afc5d5b0","applicationID":"38150566","transactionName":"Y1FVbUUFDBAAU0xeXVobZE1WEBcQIl9cUh0HBAU=","queueTime":0,"applicationTime":1,"ttGuid":"93D726A322488A18","agent":""}</script><script type="text/javascript">window.NREUM||(NREUM={}),__nr_require=function(e,n,t){function r(t){if(!n[t]){var o=n[t]={exports:{}};e[t][0].call(o.exports,function(n){var o=e[t][1][n];return r(o||n)},o,o.exports)}return n[t].exports}if("function"==typeof __nr_require)return __nr_require;for(var o=0;o<t.length;o++)r(t[o]);return r}({1:[function(e,n,t){function r(){}function o(e,n,t){return function(){return i(e,[c.now()].concat(u(arguments)),n?null:this,t),n?void 0:this}}var i=e("handle"),a=e(3),u=e(4),f=e("ee").get("tracer"),c=e("loader"),s=NREUM;"undefined"==typeof window.newrelic&&(newrelic=s);var p=["setPageViewName","setCustomAttribute","setErrorHandler","finished","addToTrace","inlineHit","addRelease"],d="api-",l=d+"ixn-";a(p,function(e,n){s[n]=o(d+n,!0,"api")}),s.addPageAction=o(d+"addPageAction",!0),s.setCurrentRouteName=o(d+"routeName",!0),n.exports=newrelic,s.interaction=function(){return(new r).get()};var m=r.prototype={createTracer:function(e,n){var t={},r=this,o="function"==typeof n;return i(l+"tracer",[c.now(),e,t],r),function(){if(f.emit((o?"":"no-")+"fn-start",[c.now(),r,o],t),o)try{return n.apply(this,arguments)}catch(e){throw f.emit("fn-err",[arguments,this,e],t),e}finally{f.emit("fn-end",[c.now()],t)}}}};a("actionText,setName,setAttribute,save,ignore,onEnd,getContext,end,get".split(","),function(e,n){m[n]=o(l+n)}),newrelic.noticeError=function(e,n){"string"==typeof e&&(e=new Error(e)),i("err",[e,c.now(),!1,n])}},{}],2:[function(e,n,t){function r(e,n){if(!o)return!1;if(e!==o)return!1;if(!n)return!0;if(!i)return!1;for(var t=i.split("."),r=n.split("."),a=0;a<r.length;a++)if(r[a]!==t[a])return!1;return!0}var o=null,i=null,a=/Version\/(\S+)\s+Safari/;if(navigator.userAgent){var u=navigator.userAgent,f=u.match(a);f&&u.indexOf("Chrome")===-1&&u.indexOf("Chromium")===-1&&(o="Safari",i=f[1])}n.exports={agent:o,version:i,match:r}},{}],3:[function(e,n,t){function r(e,n){var t=[],r="",i=0;for(r in e)o.call(e,r)&&(t[i]=n(r,e[r]),i+=1);return t}var o=Object.prototype.hasOwnProperty;n.exports=r},{}],4:[function(e,n,t){function r(e,n,t){n||(n=0),"undefined"==typeof t&&(t=e?e.length:0);for(var r=-1,o=t-n||0,i=Array(o<0?0:o);++r<o;)i[r]=e[n+r];return i}n.exports=r},{}],5:[function(e,n,t){n.exports={exists:"undefined"!=typeof window.performance&&window.performance.timing&&"undefined"!=typeof window.performance.timing.navigationStart}},{}],ee:[function(e,n,t){function r(){}function o(e){function n(e){return e&&e instanceof r?e:e?f(e,u,i):i()}function t(t,r,o,i){if(!d.aborted||i){e&&e(t,r,o);for(var a=n(o),u=v(t),f=u.length,c=0;c<f;c++)u[c].apply(a,r);var p=s[y[t]];return p&&p.push([b,t,r,a]),a}}function l(e,n){h[e]=v(e).concat(n)}function m(e,n){var t=h[e];if(t)for(var r=0;r<t.length;r++)t[r]===n&&t.splice(r,1)}function v(e){return h[e]||[]}function g(e){return p[e]=p[e]||o(t)}function w(e,n){c(e,function(e,t){n=n||"feature",y[t]=n,n in s||(s[n]=[])})}var h={},y={},b={on:l,addEventListener:l,removeEventListener:m,emit:t,get:g,listeners:v,context:n,buffer:w,abort:a,aborted:!1};return b}function i(){return new r}function a(){(s.api||s.feature)&&(d.aborted=!0,s=d.backlog={})}var u="nr@context",f=e("gos"),c=e(3),s={},p={},d=n.exports=o();d.backlog=s},{}],gos:[function(e,n,t){function r(e,n,t){if(o.call(e,n))return e[n];var r=t();if(Object.defineProperty&&Object.keys)try{return Object.defineProperty(e,n,{value:r,writable:!0,enumerable:!1}),r}catch(i){}return e[n]=r,r}var o=Object.prototype.hasOwnProperty;n.exports=r},{}],handle:[function(e,n,t){function r(e,n,t,r){o.buffer([e],r),o.emit(e,n,t)}var o=e("ee").get("handle");n.exports=r,r.ee=o},{}],id:[function(e,n,t){function r(e){var n=typeof e;return!e||"object"!==n&&"function"!==n?-1:e===window?0:a(e,i,function(){return o++})}var o=1,i="nr@id",a=e("gos");n.exports=r},{}],loader:[function(e,n,t){function r(){if(!E++){var e=x.info=NREUM.info,n=l.getElementsByTagName("script")[0];if(setTimeout(s.abort,3e4),!(e&&e.licenseKey&&e.applicationID&&n))return s.abort();c(y,function(n,t){e[n]||(e[n]=t)}),f("mark",["onload",a()+x.offset],null,"api");var t=l.createElement("script");t.src="https://"+e.agent,n.parentNode.insertBefore(t,n)}}function o(){"complete"===l.readyState&&i()}function i(){f("mark",["domContent",a()+x.offset],null,"api")}function a(){return O.exists&&performance.now?Math.round(performance.now()):(u=Math.max((new Date).getTime(),u))-x.offset}var u=(new Date).getTime(),f=e("handle"),c=e(3),s=e("ee"),p=e(2),d=window,l=d.document,m="addEventListener",v="attachEvent",g=d.XMLHttpRequest,w=g&&g.prototype;NREUM.o={ST:setTimeout,SI:d.setImmediate,CT:clearTimeout,XHR:g,REQ:d.Request,EV:d.Event,PR:d.Promise,MO:d.MutationObserver};var h=""+location,y={beacon:"bam.nr-data.net",errorBeacon:"bam.nr-data.net",agent:"js-agent.newrelic.com/nr-1130.min.js"},b=g&&w&&w[m]&&!/CriOS/.test(navigator.userAgent),x=n.exports={offset:u,now:a,origin:h,features:{},xhrWrappable:b,userAgent:p};e(1),l[m]?(l[m]("DOMContentLoaded",i,!1),d[m]("load",r,!1)):(l[v]("onreadystatechange",o),d[v]("onload",r)),f("mark",["firstbyte",u],null,"api");var E=0,O=e(5)},{}]},{},["loader"]);</script>
<title>302 Found</title>
</head><body>
<h1>Found</h1><p>The document has moved <a href="http://sadevicepacksprodus.blob.core.windows.net/pdsc/Keil.STM32F7xx_DFP.pdsc">here</a>.</p>
</body></html>                                                                                                                                                 [ 0s512 | Oct 03 08:50AM ]
[I] ~/s/a/b/p/meta-pelion-edge❯❯ cat header
HTTP/1.1 302 Found
Content-Type: text/html
Location: http://sadevicepacksprodus.blob.core.windows.net/pdsc/Keil.STM32F7xx_DFP.pdsc
Server: Microsoft-IIS/8.5
X-Powered-By: ASP.NET
X-UA-Compatible: IE=EDGE
Date: Thu, 03 Oct 2019 13:50:18 GMT
Connection: close
Content-Length: 5683

So it's probably not the redirect code.

theotherjimmy avatar Oct 03 '19 13:10 theotherjimmy

Seems like this is a bug:

curl http://sadevicepacksprodus.blob.core.windows.net/pdsc/Keil.STM32F7xx_DFP.pdsc > foo.txt
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  335k  100  335k    0     0   786k      0 --:--:-- --:--:-- --:--:--  786k

theotherjimmy avatar Oct 03 '19 14:10 theotherjimmy

In a debug build, it looks like it does not receive the redirect:

Oct 03 09:21:25.244 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32H7xx_DFP.pdsc
Oct 03 09:21:25.246 ERRO download of "https://www.keil.com/pack/Keil.STM32H7xx_DFP.pdsc" failed: unexpected end of file

If it worked it would look like:

Oct 03 09:21:25.227 DEBG Starting GET of http://mcuxpresso.nxp.com/cmsis_pack/repo/NXP.LPCXpresso54102_BSP.pdsc
Oct 03 09:21:25.227 DEBG Redirecting from http://mcuxpresso.nxp.com/cmsis_pack/repo/NXP.LPCXpresso54102_BSP.pdsc to https://mcuxpresso.nxp.com/cmsis_pack/repo/NXP.LPCXpresso54102_BSP.pdsc
Oct 03 09:21:25.227 DEBG Starting GET of https://mcuxpresso.nxp.com/cmsis_pack/repo/NXP.LPCXpresso54102_BSP.pdsc

theotherjimmy avatar Oct 03 '19 14:10 theotherjimmy

I am unable to reproduce the problem:

jkrech@E123565 MINGW64 /c/tmp/test
$ curl http://sadevicepacksprodus.blob.core.windows.net/pdsc/Keil.STM32F7xx_DFP.pdsc -D header
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0<?xml version="1.0" encoding="UTF-8"?>

<package schemaVersion="1.6.0" xmlns:xs="http://www.w3.org/2001/XMLSchema-instance" xs:noNamespaceSchemaLocation="PACK.xsd">
  <vendor>Keil</vendor>
  <name>STM32F7xx_DFP</name>
  <description>STMicroelectronics STM32F7 Series Device Support, Drivers and Examples</description>
  <url>https://www.keil.com/pack/</url>

  <releases>
    <release version="2.12.0" date="2019-07-17">

From my perspective (I am just uploading a pack through a Web Interface) there is nothing special about the Keil.STM32MH7xx_DFP.pdsc. For better download performance around the world we host the files on Azure. I do expect all pdsc files at www.keil.com/pack to redirect.

Once you instruct curl to follow the redirect I do see the pdsc file being properly downloaded on my machine () .

Sorry if I cannot provide any more insights. Please note that I also validated that the MDK Pack Installer would be able to download successfully.

jkrech avatar Oct 04 '19 13:10 jkrech

I think you're right; I think it's something going wrong in cmsis-pack-manager. It's odd that it only affects these 3 packs, and that it's consistent.

theotherjimmy avatar Oct 04 '19 14:10 theotherjimmy

Perhaps a strange idea, but what if we replaced that download code by a call to "curl" itself, i.e. curl <Uri> -L ><PathBuf>, if you see what I mean. Seems curl can handle the redirects, then why not use it?

JanneKiiskila avatar Oct 04 '19 18:10 JanneKiiskila

Because that would be a nasty dependency to manage.

flit avatar Oct 04 '19 18:10 flit

@JanneKiiskila all this talk about handling redirects is a red herring, as this fails before invoking any redirection code.

theotherjimmy avatar Oct 04 '19 19:10 theotherjimmy

Yep, that's what you get when a noob starts looking at the rust code we have in this repo without any real understanding. Title and description modified.

JanneKiiskila avatar Oct 04 '19 19:10 JanneKiiskila

The older I get, the more I know what I don't know.

JanneKiiskila avatar Oct 04 '19 19:10 JanneKiiskila

Thanks for changing the title. I'm trying to root cause the issue here. This is weird that curl does not have the same issue.

theotherjimmy avatar Oct 04 '19 19:10 theotherjimmy

I have ruled out concurrency, as I removed concurrent downloads in a test build without affecting the problem behavior.

theotherjimmy avatar Oct 04 '19 19:10 theotherjimmy

Thanks for looking into this!

JanneKiiskila avatar Oct 04 '19 19:10 JanneKiiskila

Snippet from strace:

Oct 04 14:22:27.717 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc
recvfrom(32, "", 18437, 0, NULL, NULL)  = 0
epoll_ctl(27, EPOLL_CTL_DEL, 32, 0x7ffd8dc89a70) = 0
close(32)  

A 0 from recvfrom indicates that "If no messages are available to be received and the peer has performed an orderly shutdown, recvfrom() shall return 0".

I'm thinking that CPM might be sending an invalid GET to the server and it's responds by shutting down the connection.

theotherjimmy avatar Oct 04 '19 19:10 theotherjimmy

I just traced a clean download of everything and it looks like all of these are https keil.com packs being, and these failing to download packs are the only packs that use https from keil.com.

❯ rg "https.*keil.com"
trace
8781:Oct 04 14:43:24.319 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc
8783:Oct 04 14:43:24.319 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc
8812:Oct 04 14:43:24.344 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32G0xx_DFP.pdsc
8814:Oct 04 14:43:24.344 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32G0xx_DFP.pdsc
8906:Oct 04 14:43:24.461 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc
8933:Oct 04 14:43:24.488 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32G0xx_DFP.pdsc
9082:Oct 04 14:43:24.597 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc
9084:Oct 04 14:43:24.600 ERRO download of "https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc" failed: unexpected end of file
9099:Oct 04 14:43:24.623 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32G0xx_DFP.pdsc
9101:Oct 04 14:43:24.627 ERRO download of "https://www.keil.com/pack/Keil.STM32G0xx_DFP.pdsc" failed: unexpected end of file
10102:Oct 04 14:43:26.258 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32H7xx_DFP.pdsc
10104:Oct 04 14:43:26.258 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32H7xx_DFP.pdsc
10227:Oct 04 14:43:26.394 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32H7xx_DFP.pdsc
10319:Oct 04 14:43:26.531 DEBG Starting GET of https://www.keil.com/pack/Keil.STM32H7xx_DFP.pdsc
10321:Oct 04 14:43:26.533 ERRO download of "https://www.keil.com/pack/Keil.STM32H7xx_DFP.pdsc" failed: unexpected end of file

theotherjimmy avatar Oct 04 '19 19:10 theotherjimmy

Why are there so many Starting GET of for the same file? Should not one be enough, or is the debug print just slightly misleading?

JanneKiiskila avatar Oct 04 '19 20:10 JanneKiiskila

It looks like this might be a TLS cyphersuite miss-match. CMP uses Rustls for TLS, and as such does not support TLS < 1.2. Using Openssl, I was able to figure out that www.keil.com supports the following cyphersuites:

tls1_2:	ECDHE-RSA-AES256-SHA384
tls1_2:	ECDHE-RSA-AES128-SHA256
tls1_2:	ECDHE-RSA-AES256-SHA
tls1_2:	ECDHE-RSA-AES128-SHA
tls1_2:	AES256-SHA256
tls1_2:	AES128-SHA256
tls1_2:	AES256-SHA
tls1_2:	AES128-SHA

This might be a TLS cyphersuite mismatch.

theotherjimmy avatar Oct 04 '19 20:10 theotherjimmy

If curl is a bad idea, could we use a Rust -based solution? Seems Rust has a HTTP download crate called reqwest.

(And this reply came way after the TLS analysis, that's interesting and reqwest also uses rustls then it will be impacted by this the same way.)

JanneKiiskila avatar Oct 04 '19 20:10 JanneKiiskila

@JanneKiiskila I'm not sure. I was thinking the same thing: why are we downloading the same thing 3-4 times? I'm going to put that aside for now and try to track down this TLS issue.

theotherjimmy avatar Oct 04 '19 20:10 theotherjimmy

I'm just wondering could it be an DDoS protection mechanism, i.e. it blocks the connection because it thinks someone is doing too much at same time?

JanneKiiskila avatar Oct 04 '19 20:10 JanneKiiskila

It could be a DDoS protection mechanism.

I tried the Rustls example with www.keil.com:

❯ cargo run --example tlsclient -- --http expired.badssl.com
warning: /home/jimmy/src/ctz/rustls/rustls/Cargo.toml: file found to be present in multiple build targets: /home/jimmy/src/ctz/rustls/rustls/tests/benchmarks.rs
    Finished dev [unoptimized + debuginfo] target(s) in 0.04s
     Running `target/debug/examples/tlsclient --http expired.badssl.com`
TLS error: WebPKIError(CertExpired)
Connection closed
                                                                [ 0s196 | Oct 04 03:11PM ]
[I] ~/s/c/rustls❯❯ cargo run --example tlsclient -- --http www.keil.com
warning: /home/jimmy/src/ctz/rustls/rustls/Cargo.toml: file found to be present in multiple build targets: /home/jimmy/src/ctz/rustls/rustls/tests/benchmarks.rs
    Finished dev [unoptimized + debuginfo] target(s) in 0.03s
     Running `target/debug/examples/tlsclient --http www.keil.com`
EOF
Connection closed
                                                                [ 0s356 | Oct 04 03:11PM ]
[I] ~/s/c/rustls❯❯ cargo run --example tlsclient -- --http mozilla-modern.badssl.com
warning: /home/jimmy/src/ctz/rustls/rustls/Cargo.toml: file found to be present in multiple build targets: /home/jimmy/src/ctz/rustls/rustls/tests/benchmarks.rs
    Finished dev [unoptimized + debuginfo] target(s) in 0.11s
     Running `target/debug/examples/tlsclient --http mozilla-modern.badssl.com`
HTTP/1.1 200 OK
Server: nginx/1.10.3 (Ubuntu)
Date: Fri, 04 Oct 2019 20:16:32 GMT
Content-Type: text/html
Content-Length: 644
Last-Modified: Wed, 11 Sep 2019 15:20:49 GMT
Connection: close
ETag: "5d7910d1-284"
Strict-Transport-Security: max-age=15768000
Cache-Control: no-store
Accept-Ranges: bytes

<!DOCTYPE html>
<html>
<head>
  <meta name="viewport" content="width=device-width, initial-scale=1">
  <link rel="shortcut icon" href="/icons/favicon-green.ico"/>
  <link rel="apple-touch-icon" href="/icons/icon-green.png"/>
  <title>mozilla-modern.badssl.com</title>
  <link rel="stylesheet" href="/style.css">
  <style>body { background: green; }</style>
</head>
<body>
<div id="content">
  <h1>
    mozilla-modern.<br>badssl.com
  </h1>
</div>

<div id="footer">
  This site uses the Mozilla &ldquo;<a href="https://wiki.mozilla.org/Security/Server_Side_TLS#Modern_compatibility">Modern</a>&rdquo; TLS configuration.
</div>

</body>
</html>
Plaintext read error: Custom { kind: ConnectionAborted, error: "CloseNotify alert received" }
Connection closed

It's the middle one. Other commands provided for context.

theotherjimmy avatar Oct 04 '19 20:10 theotherjimmy

@JanneKiiskila Good digging in libraries. I'm using hyper + rustls. reqwest is built on top of hyper and a i would be happy to use reqwest if it fixes the problem. Otherwise, I see no reason to switch, and I see a small downside to adding more dependencies.

theotherjimmy avatar Oct 04 '19 20:10 theotherjimmy

A multi-curl should theoretically then also fail, if there was a DDoS mechanism there, but it seems to work. At least this;

curl https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc -L >1.txt & curl https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc -L >2.txt & curl https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc -L >3.txt & curl https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc -L >4.txt & curl https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc -L >5.txt & curl https://www.keil.com/pack/Keil.STM32F7xx_DFP.pdsc -L >6.txt

Got all 1...6.txt files down and they are all the same, with the proper content.

JanneKiiskila avatar Oct 04 '19 20:10 JanneKiiskila

have you tried capturing the tls handshake with wireshark?

flit avatar Oct 04 '19 20:10 flit

@flit i have not tried capturing the tls handshake with wireshark yet. Good suggestion, I'll give that a shot.

theotherjimmy avatar Oct 04 '19 20:10 theotherjimmy

i'm also trying it, but you probably have more experience 😄

flit avatar Oct 04 '19 20:10 flit