Shopify / themekit

Shopify theme development command line tool.
https://shopify.dev/tools/theme-kit
MIT License
1.2k stars 375 forks source link

theme download gets stuck at 97% #801

Closed alexissel closed 3 years ago

alexissel commented 4 years ago

Hi there,

I recently updated themekit to latest version (1.1.1) and since then it cannot download all the files... I tried with 3 different themes and all of them get stuck around 97-98%

[development] Warning, this is the live theme on XXXXX-THEME. [development] 389|401 [===================================================================>--] 97 %

Any thoughts on this?

Thanks

OS: Mac Themekit: v1.1.1

tanema commented 4 years ago

Hey @alexissel Does it get stuck forever? Since v1.0 themekit, there are 2 things that would make it pause

If these things might be combined as well as the backoff in the retrying it might take about 10 seconds to finish or fail completely

andyw8 commented 4 years ago

Also @alexissel, can you try running running in verbose mode (-v) to help determine which files it's 'stuck' on?

henry-philosophydigital commented 4 years ago

Same issue here. Since the latest update I have been struggling to pull any themes.

Now it seems to always stick at 97%. (Edit: it sometimes fails at other points too, however i've seen 97% more than once)

-v shows it sticking at a standard .liquid file in the sections folder.

runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x145c8f2]

Thanks

andyw8 commented 4 years ago

Thanks, that's very helpful. It seems that when in non-verbose mode the error is being hidden so I've logged that as a separate issue #802.

Are you able to determine which particular liquid files are not being uploaded? If so, can you check if you can upload any of them individually, e.g. theme upload myfile.liquid?

andyw8 commented 4 years ago

Also, are you seeing a stacktrace below that error, e.g. with a reference to any .go files?

alexissel commented 4 years ago

@tanema , yes, it gets stuck forever.

@andyw8 , I just run the command in verbose mode (theme download -v) and for the first 17 files it says "No Change", and for the rest of them, says "Successfully wrote". No error message.

henry-philosophydigital commented 4 years ago

See below for a couple of recent fails:

`[development] Successfully wrote sections/password-template.liquid to disk (Remote: b4a6f5b07911860fd00fd632cbfc1ea7, Local: ) panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x145c8f2] goroutine 300 [running]: github.com/Shopify/themekit/src/httpify.(*HTTPClient).doWithRetry(0xc000206280, 0xc0007d6900, 0x0, 0x0, 0x1, 0xc00036a740, 0x0) /Users/andyw8/src/github.com/Shopify/themekit/src/httpify/client.go:130 +0x102 github.com/Shopify/themekit/src/httpify.(*HTTPClient).do(0xc000206280, 0x1577561, 0x3, 0xc0008000c0, 0x56, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /Users/andyw8/src/github.com/Shopify/themekit/src/httpify/client.go:105 +0x5d1 github.com/Shopify/themekit/src/httpify.(*HTTPClient).Get(0xc000206280, 0xc0008000c0, 0x56, 0x0, 0x19dd860, 0xd, 0xd) /Users/andyw8/src/github.com/Shopify/themekit/src/httpify/client.go:70 +0x6d github.com/Shopify/themekit/src/shopify.Client.GetAsset(0x7ffeefbffcd9, 0xb, 0xc0001f83c0, 0x18, 0x19dd860, 0xd, 0xd, 0x19fa1e0, 0x0, 0x0, ...) /Users/andyw8/src/github.com/Shopify/themekit/src/shopify/theme_client.go:263 +0x178 github.com/Shopify/themekit/cmd.download.func1(0xc00022c900, 0xc0004adcf0, 0xc0002da340, 0x12, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /Users/andyw8/src/github.com/Shopify/themekit/cmd/download.go:62 +0x4a4 created by github.com/Shopify/themekit/cmd.download /Users/andyw8/src/github.com/Shopify/themekit/cmd/download.go:52 +0x1bb` `[development] Successfully wrote assets/swatch-get-fierce-leopard-print-coloured-insert-mug-green.png to disk (Remote: 2e0337daf78ca40484e5309f81c6e7e8, Local: ) panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x145c8f2] goroutine 283 [running]: github.com/Shopify/themekit/src/httpify.(*HTTPClient).doWithRetry(0xc0000ce780, 0xc000888600, 0x0, 0x0, 0x1, 0xc0003b6cc0, 0x0) /Users/andyw8/src/github.com/Shopify/themekit/src/httpify/client.go:130 +0x102 github.com/Shopify/themekit/src/httpify.(*HTTPClient).do(0xc0000ce780, 0x1577561, 0x3, 0xc0003fca20, 0x58, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /Users/andyw8/src/github.com/Shopify/themekit/src/httpify/client.go:105 +0x5d1 github.com/Shopify/themekit/src/httpify.(*HTTPClient).Get(0xc0000ce780, 0xc0003fca20, 0x58, 0x0, 0x19dd860, 0xd, 0xd) /Users/andyw8/src/github.com/Shopify/themekit/src/httpify/client.go:70 +0x6d github.com/Shopify/themekit/src/shopify.Client.GetAsset(0x7ffeefbffcd9, 0xb, 0xc000496c60, 0x18, 0x19dd860, 0xd, 0xd, 0x19fa1e0, 0x0, 0x0, ...) /Users/andyw8/src/github.com/Shopify/themekit/src/shopify/theme_client.go:263 +0x178 github.com/Shopify/themekit/cmd.download.func1(0xc0000aa900, 0xc0003288a0, 0xc0000d2220, 0x14, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /Users/andyw8/src/github.com/Shopify/themekit/cmd/download.go:62 +0x4a4 created by github.com/Shopify/themekit/cmd.download /Users/andyw8/src/github.com/Shopify/themekit/cmd/download.go:52 +0x1bb`

Realised that perhaps I'm wrong to say that it 'failed' on a certain file - the most I can specify is the last successful transfer.

Also, after one of these fails, the rest of the download seem to 'pick up' where it left off by running the same theme get command.

Cheers

andyw8 commented 4 years ago

Thanks, this looks like the same issue as #790 (PR in #794) so we'll aim to prioritize that fix.

alexissel commented 4 years ago

Thanks @andyw8 ! Hope you'll fix this soon :)

alexissel commented 4 years ago

@andyw8 , until you'll release a fix for this, how can I downgrade themekit to v1.0.3 (latest release which works properly)?

andyw8 commented 4 years ago

@alexissel You can run theme update --version=1.0.3

IllidanMalar commented 4 years ago

I have the same problem, I use themekit for many projects, but a couple of them get stuck at advanced download state. This is usually 98% or 99%, downgrading themekit will fix it. The problem occurs without any type of error, even the verbose mode does not throw any exception.

DanPete commented 4 years ago

I am also having this issue with Themekit 1.1.0 and 1.1.0 there are no error when I run it in verbose mode, it just hangs between 97% and 99%. I have tried running the command multiple times to see if it could complete occasionally, but it seems on some themes it never completes.

OS: Ubuntu 18 Themekit: v1.1.0 and v1.1.1

andyw8 commented 4 years ago

@alexissel We've fixed the issue and will have a new release of Theme Kit out very soon.

andyw8 commented 4 years ago

@alexissel You can now run theme update to update to v1.1.2. Please re-open the issue if you are still having problems.

alexissel commented 4 years ago

@andyw8 , the issue is still there... nothing changed on my end. I run theme download -v and didn't get any error messages but the download still gets stuck after 90%

andyw8 commented 4 years ago

@alexissel Thanks for reporting, we'll continue to look into.

DanPete commented 4 years ago

Also, still having an issue with this. No errors with verbose on, just stuck at 99% and two files remaining to download. I think it may actually be completing the whole theme download based on my git diff when I try to re-download with v1.0.3, but the visual representation of complete download or in verbose mode shows that it never finished and just hangs on v1.1.0, 1.1.1, and 1.1.2

nikushx commented 4 years ago

Still having this issue as well on 1.1.2. tried downgrading to 1.0.3 and it seems to work.

tanema commented 4 years ago

I have been looking into this and it only seems to happen on the first download of some themes. I just did it with one theme and it got stuck on a locales file for some reason locales/tr.json

Is it only happening on download for everyone?

Notes for self

Update again:

I added logging that looks like (and used `sort` to group them) ``` 0/130 done assets/banner.jpg 0/130 downloading assets/banner.jpg 0/130 starting assets/banner.jpg 0/130 writing assets/banner.jpg 1/130 done assets/gift-card.scss.liquid 1/130 downloading assets/gift-card.scss.liquid 1/130 starting assets/gift-card.scss.liquid 1/130 writing assets/gift-card.scss.liquid ... ``` Used some ruby ```ruby results = {} File.readlines('log.txt').each do |line| next if line.strip == "" parts = line.split(' ') results[parts[0]] ||= {actions: [], fname: parts[2]} results[parts[0]][:actions] << parts[1] end puts results.select { |id, res| res[:actions].count < 4 } ``` And got ``` {"47/130"=>{:actions=>["downloading", "starting"], :fname=>"sections/advanced-content.liquid"}, "65/130"=>{:actions=>["downloading", "starting"], :fname=>"sections/product-recommendations.liquid"}} ```

2 files that started downloading but never made it to the write stage. However the http adapter is not throwing response errors or throttling errors. My next steps are http client configuration, and retry mechanism might have a black hole in it somewhere still as well.

Update Again Again:

I am narrowing in on the http adapter. I believe since we are able to push through so many more requests, we are reaching the limits of the default golang http client. It now needs more configuration to handle idle connections more gracefully.

tanema commented 4 years ago

Okay I have put up a draft PR with more information on where I think the issues lay. You can see it here https://github.com/Shopify/themekit/pull/819

And you can try this patch out by running theme update --version=v1.1.3-issue801 and validate my approach.

VladimirCatrici commented 4 years ago

I have had this issue for a few times so far, here are my observations: I noticed it happens with larger themes rather than to smaller ones. Generally stuck on around ~96%-99%. No errors in verbose mode. Once I left it hanging and files downloaded eventually, but it took hours.

@tanema, I tried your patch, unfortunately, didn't help.

tanema commented 4 years ago

Can anyone else test this to see if it fixes it for you? I am fairly certain about where the problem lies, I just need to figure out the correct tweaks/settings.

tanema commented 4 years ago

I have updated the v1.1.3-issue801 version with some more connection stability configurations, please try it again.

alexissel commented 4 years ago

Hey @tanema ,

I updated themekit to your version (v1.1.3-issue801) and I did the following:

  1. run theme download for theme X = got stuck at 56% (after 2 min of waiting I pressed Ctrl+C)
  2. run theme download -v for same theme X = Downloaded: 546, No Changes: 29, Errored: 0 - I think it worked
  3. run theme download for theme Y = download goes to 66% and it stays there for ~3 min, then it goes again to 87% (gets stuck for 2 min) and then it goes to 100%
  4. run theme download for theme Z = download goes to 73% and it stays for ~2 min, then it goes to 100%

So... I think it works?! I'll try again tomorrow, maybe I have some issues with my internet connection...

tanema commented 4 years ago

Okay! We are making progress! Those pauses are definitely from throttling, before the most recent change, requests were just strictly throttled to 2 per second. In the most recent release, the requests are all thrown at shopify as fast as possible and then paused when we start getting 409 responses. At 546 files that would make more sense because I am sure the pausing would accumulate over the progress of all those files. I will take a look at some things I can do to smooth things out a bit so the pauses will be lessened.

andyw8 commented 4 years ago

Perhaps we could add something in the output to indicate when throttling is happening?

kasim444 commented 4 years ago

I faced the same problem in v1.1.2. but when I downgraded the version to 1.0.3, the problem was gone.

milesw commented 4 years ago

Tested v1.1.3-issue801 and still experiencing stalls around 90-99%. Theme contains 193 files.

After it stalls, if I leave it downloading, sometimes it will slowly move along 1-2% more, but never finishes. No errors reported with verbose flag.

If API throttling is the issue here, wouldn't all users be affected?

Happy to help test further PRs!

binarymonkey84 commented 4 years ago

I also have this issue with 1.1.2, stuck on 99%

robtry commented 4 years ago

The working version 1.0.3 sudo theme update --version=1.0.3

austinhutchison commented 4 years ago

I tried v.1.1.3-issue801 with verbose output and it worked. TBH I'm not sure if it was the branch that worked or just patience since I could track progress with the verbose output.

It does seem that theme download now is getting all files again rather than getting only the changed files

binarymonkey84 commented 4 years ago

@tanema Does this mean this issue is now fixed? If so, how can we get the updated version?

tanema commented 4 years ago

Sorry, I cannot confirm it has. I marked the PR as will-fix and now I am surprised that it auto-closed it

Edit: I have however identified several small issues with http connections and throttling so I believe it should solve most issues. Please try updating (theme update --version=v1.1.3-issue801) and trying again.

axis80 commented 4 years ago

I have been running into this problem with hanging downloads for weeks or months. Like others, I tried updating to 1.1.2 and that did not fix the issue. I am on Ubuntu 20.04.

I just updated to your version v1.1.3-issue801 and ran theme get -v -p=<password> -s=<shopname.myshopify.com> -t=<themeid> against an empty download folder. On the first execution, it ran into a lot of errors like these:

[development] error downloading locales/en.default.json: DNS problem while connecting to Shopify, this indicates a problem with your internet connection

and

[development] error downloading assets/base-comment_form_bg.png: received a malformed response from shopify, this usually indicates a problem with your connection

FWIW, my Internet connection didn't seem unstable. I am sitting here streaming music and loading other web sites just fine.

I ended up hitting Ctrl-C on the download. I then cleared out the download folder and re-ran the command. This time, it hung for periods of time. There were a lot of errors like this one:

[development] error writing assets/lightblue-h2_underline.png: open /home/derrick/Scratch/Client Name/theme/assets/lightblue-h2_underline.png: too many open files

It eventually completed with "Downloaded: 300, No Changes: 0, Errored: 2".

I hit the up arrow and re-ran the same command in an attempt to download the errored files. It again ran into errors on a couple files. It told me:

[development] error writing assets/lightblue-h2_underline.png: open /home/derrick/Scratch/Client Name/theme/assets/lightblue-h2_underline.png: too many open files [development] error downloading assets/purple-sort.png: DNS problem while connecting to Shopify, this indicates a problem with your internet connection

This time it completed with "Downloaded: 245, No Changes: 55, Errored: 2".

I couldn't get it to work reliably so I eventually rolled back to 1.0.3.

Hopefully that helps at least a little bit.

vfonic commented 4 years ago

I just did theme update --version=v1.1.3-issue801 and ran theme download -v and it still hangs unfortunately. :/

The theme has 517 files.

I also got these kinds of errors (along with the DNS ones) on subsequential runs:

[development] error writing assets/home5_slide3.png: open /absolute/path/to/dev/dir/assets/home5_slide3.png: too many open files

EDIT: theme download worked just fine with v1.0.3 I upgraded to 1.1.3-issue801 again to try again, but it still hangs.

adrach commented 4 years ago

I do not see freezing anymore (v1.1.2) but there is definitely excessive throttling

vfonic commented 4 years ago

I have a theme that freezes every time. I let it run the whole night. It still didn't finish downloading.

@tanema if you need the theme so you can repro this issue consistently, email me at viktor.fonic[at]gmail.com.

This is a regression that is not present in 1.0.2. Would it be possible to revert the changes responsible for this issue?

That would help me a lot, as I'd be able to use much faster theme download from 1.1.2, after theme download finally passes.

EDIT:

Here's what we know so far:

  1. There's a bug (in v1.1.2?)
  2. We know this bug wasn't present in earlier versions (v1.0.2?)
  3. This bug prevents some users from using theme download command altogether
  4. This bug was reported more than a month ago (Sep 22nd)

Wouldn't it be better if the changes were reverted until proven that they work? There are 13 👍 to the original post of this issue and many other developers joined in with comments. This is clearly an issue.

tanema commented 4 years ago

Would it be possible to revert the changes responsible for this issue?

This would mean just reverting to 1.0.2. There are some foundational changes since them and reverting them would just mean going back to that version number. If we knew the exact issues for this problem we would have fixed them of course.

That would help me a lot, as I'd be able to use much faster theme download from 1.1.2, after theme download finally passes.

That would not be the case if the changes were reverted

Wouldn't it be better if the changes were reverted until proven that they work?

No, since developers are able to roll back themekit to an earlier version this means that they are not blocked from continuing their work. Without developers using this version and being able to identify which instances that it does work and which it does not, I have no recourse to fixing this issue and making themekit better. This change is actually working and improving development for a lot of developers but there is some edge case that we have not identified yet that is effecting a not-small sample of developers and we continue to work on this.

vfonic commented 4 years ago

Thanks, @tanema!

I understand now. I thought there were two separate pieces of functionality that were added to last couple of versions: 1) running multiple requests in parallel 2) downloading files based on if their checksum changed

If we could revert 1 and keep 2, that would be perfect. But seems like that's not possible...

Without developers using this version and being able to identify which instances that it does work and which it does not, I have no recourse to fixing this issue and making themekit better.

I can send you the full theme file if you want. So far, it hangs 100% of the times.

tanema commented 4 years ago

running multiple requests in parallel

This has been implemented since version 0.0.1

I will be in contact to get theme information for you, that will be helpful, thank you.

NTXAggie commented 4 years ago

Hi, just wanted to comment that version 1.1.2 is still hanging for me at 99% on a basic Debut theme (hardly any customization as it is my dev store). I downgraded to 1.0.2 and that resolved it.

tanema commented 4 years ago

Okay some things I have learned. While running theme download on @vfonic I found

Is anyone having issue with any requests on themekit after their command pauses? For instance if you try to run theme download again, does it pause again? I ask because this looks like it is getting squashed by Shopify's bot detection. In trying to optimize themekit's functionality, we have made it a little bit too fast 😅

I may just simply have to limit the amount of inflight requests at a single time so that when a 429 response is received, another 20 requests are not still in flight causing our algorithms to keep counting requests.

vfonic commented 4 years ago

I noticed that if I run theme download and, once it reaches ~90% (it's about to or just started to fail new requests), if I kill that process and run theme download again, I will get much more failures. You can see this if you add --verbose which shows more requests failing.

jack-fdrv commented 4 years ago

image It happens to often for me.

adriangzz commented 4 years ago

Has anybody been able to solve this? I've tried with v1.1.2 and v1.1.3-issue801 to download a theme with no luck.

Update: v1.03 worked

VladimirCatrici commented 4 years ago

Yep, v1.0.3 is stable and is working perfectly. It doesn't make sense to update until this issue is fixed.

absorpheus commented 4 years ago

I thought I'd comment here as I was having the same issue when using @shopify/themekit where the download would freeze at 99% when getting a theme from a store.

I was using @shopify/themekit (v1.1.6) which was using themekit v1.1.1 as the binary under the hood.

Downgrading @shopify/themekit to v1.1.4 fixed this for me as it's the most recent version to have themekit v1.0.3 which seems to be stable at the moment

thisischrisj commented 4 years ago

Same issue on 1.1.2. Got stuck at 174/175 - 99%

Rolling back to 1.0.3 worked

tanema commented 4 years ago

Okay I have opened a PR #839 to fix this. Thanks to @vfonic for lending me his theme to test. Please try the update again theme update --version=v1.1.3-issue801 and see if it works for you. I have tested with @vfonic theme and what was breaking before hand, is now fixed.

An unrelated note on the on the recent optimizations as well since I have seen the same confusion from people here. For the content checking (checksums) there has been some confusion on how that works. If you are only running download right now, you will not see it optimized. We were unable to backfill the (100s of) terrabytes of assets checksums so they will only be in effect if you run a deploy so that every asset will get updated with a checksum and you will see the optimization after that.

Please let me know how the update goes. Since we are easing back on a lot of our internal work in preparation for BFCM I am hoping to ship a lot of my pending work in the next few weeks.