After newest libgifski update the generator needs few seconds to start and the progress is laggy #95
sunshinejr posted onGitHub
The bounty here now applies to https://github.com/sindresorhus/Gifski/issues/180 instead.
This is the video I reproduced it with.
I've made a branch with logging: https://github.com/sindresorhus/Gifski/tree/logging-for-95 I've wrapped the generateCGImagesAsynchronously
callback in a DispatchQueue, so libgifski won't block it.
Here's the log output:
generate 0 2019-06-24 14:51:53 +0000
generate 1 2019-06-24 14:51:53 +0000
generate 2 2019-06-24 14:51:53 +0000
generate 3 2019-06-24 14:51:54 +0000
generate 4 2019-06-24 14:51:54 +0000
generate 5 2019-06-24 14:51:54 +0000
generate 6 2019-06-24 14:51:54 +0000
generate 7 2019-06-24 14:51:54 +0000
generate 8 2019-06-24 14:51:54 +0000
generate 9 2019-06-24 14:51:54 +0000
generate 10 2019-06-24 14:51:54 +0000
generate 11 2019-06-24 14:51:54 +0000
generate 12 2019-06-24 14:51:54 +0000
generate 13 2019-06-24 14:51:54 +0000
generate 14 2019-06-24 14:51:55 +0000
generate 15 2019-06-24 14:51:55 +0000
generate 16 2019-06-24 14:51:55 +0000
generate 17 2019-06-24 14:51:55 +0000
generate 18 2019-06-24 14:51:55 +0000
generate 19 2019-06-24 14:51:55 +0000
generate 20 2019-06-24 14:51:55 +0000
generate 21 2019-06-24 14:51:55 +0000
generate 22 2019-06-24 14:51:55 +0000
generate 23 2019-06-24 14:51:55 +0000
generate 24 2019-06-24 14:51:55 +0000
generate 25 2019-06-24 14:51:55 +0000
generate 26 2019-06-24 14:51:55 +0000
generate 27 2019-06-24 14:51:55 +0000
generate 28 2019-06-24 14:51:55 +0000
generate 29 2019-06-24 14:51:55 +0000
generate 30 2019-06-24 14:51:55 +0000
generate 31 2019-06-24 14:51:55 +0000
generate 32 2019-06-24 14:51:55 +0000
generate 33 2019-06-24 14:51:56 +0000
generate 34 2019-06-24 14:51:56 +0000
write 2019-06-24 14:52:02 +0000
write 2019-06-24 14:52:02 +0000
write 2019-06-24 14:52:02 +0000
write 2019-06-24 14:52:02 +0000
write 2019-06-24 14:52:02 +0000
write 2019-06-24 14:52:02 +0000
write 2019-06-24 14:52:02 +0000
write 2019-06-24 14:52:02 +0000
write 2019-06-24 14:52:02 +0000
write 2019-06-24 14:52:02 +0000
...
Notice how it takes 8 seconds from the last generate
log to the first write
log.
@kornelski Any ideas?
I also noticed that most of the time when cancelling the conversion it will crash.
What's the order of calls to the library? Are you setting the write callback before the frames?
@issuehunt has funded $80.00 to this issue.
- Submit pull request via IssueHunt to receive this reward.
- Want to contribute? Chip in to this issue via IssueHunt.
- Checkout the IssueHunt Issue Explorer to see more funded issues.
- Need help from developers? Add your repository on IssueHunt to raise funds.
I spent some time and figured out the culprit. Seems like gifski lib goes to the writing block after we add 3 frames. The problem with this video is that adding these 3 frames takes a long time (2 seconds per each for me). Because of that there is 6 secs+ delay on this video.
I extracted one of the frames and tried to create a gif with that frame using the rust lib and it was a lot quicker.
Command I used:
/gifski frame1.png frame1.png frame1.png -o gif.gif
Frame I used:
There might be a difference in how we use the lib, as we pass a data buffer vs I used a PNG image as a frame. Any suggestions @kornelski?
Edit: I also tried to see if the in-memory-gif-generating is a problem, but getting similar results using the version with writing to file.
Time profiler
Release 1.7.0
<img width="1009" alt="Screenshot 2019-07-22 at 12 13 55" src="https://user-images.githubusercontent.com/51816980/61628519-72970c00-ac7a-11e9-81f3-898b73dbff86.png">
Release 1.8.0
<img width="1010" alt="Screenshot 2019-07-22 at 11 31 58" src="https://user-images.githubusercontent.com/51816980/61628541-7f1b6480-ac7a-11e9-90e9-bed0ad138884.png">
It's clear the function 'addFrame' is taking orders of magnitude longer for the first several frames.
Regarding the crashing, it seems to me that the variable gifData
in the file Gifski.swift
is potentially touched from several threads and it might need to be locked.
@BowdusBrown the crash is already fixed in the #94 PR. The only thing right now is the delay in creating frames. I might try to go back to the old gifski version and see if it helps.
Also, thanks for the findings from the instruments!
The compression algorithm hasn't changed between versions, so the raw CPU requirements are identical.
The only thing that has changed is that now the library spawns a thread internally, instead of expecting the app to use it from two threads.
So I expect delays to come from mutexes/locking/threads waiting on each other.
If you take a closer look at my screenshots above, you can see the icon representing code belonging to Gifski (the icon of a human head and shoulders) is shaded out in calls lower down. I believe those calls are inside the libgifski library and I'm curious to know why they appear shaded out in instruments. Anyone know?
Okay I did a little bit more research. This video behaves similarly between different libgifski versions, changing between writing/memory doesn't make a difference either. It just seems like this video needs a little bit more time to add frames than normally (I mean it's a lot of pixels).
Edit: it seems like the old Gifski version was a lot quicker in progress and didn't need few second to starts. So not sure what went wrong when I was testing the previous lib version, but there is a big difference.
So I was again researching the topic as few things didn't make sense to me. And it turns out that the problem was the optimization level. Basically when we compiled Gifski in Release scheme, everything was back to normal. It only behaved that way on Debug.
There's still the problem that gifski.setWriteCallback
(or rather gifski_set_write_callback
underneath) blocks the thread even though it's documented as being non-blocking. In https://github.com/sindresorhus/Gifski/commit/28be9dceb1878ec175ee0bb0acb92357bab912d3, I had to wrap the generator.generateCGImagesAsynchronously
callback in DispatchQueue.global().async
.
I can't reproduce that problem. gifski_set_write_callback
doesn't wait for anything. It only acquires one lock to save thread handle, but there's nothing else that could hold that lock.
In 6f6bf34f4fedf4be7aead46bcf230310e2f1665b I've added another warning in case things were called out of order.
@BowdusBrown the crash is already fixed in the #94 PR. The only thing right now is the delay in creating frames. I might try to go back to the old gifski version and see if it helps.
Also, thanks for the findings from the instruments!
I wouldn't be so sure...
<img width="1016" alt="Screenshot 2019-08-15 at 07 05 39" src="https://user-images.githubusercontent.com/51816980/63075916-2c586400-bf2b-11e9-8c1d-b26e34d9213d.png">
Happened when pressing cancel.
I'm checked out at 6f6bf34f4fedf4be7aead46bcf230310e2f1665b
Ah yeah, I didn't update the comment, apologies. But after I wrote that comment, we still could get the crash on debug which is non-ideal... On release it seems to be working okayish.
No worries. I have provided a fix https://github.com/sindresorhus/Gifski/pull/124 but really the root cause of why gifData is deallocated early is the real fix. It seems to be happening inside the static library.
Closing as I don't think this is a problem anymore. The bounty here now applies to https://github.com/sindresorhus/Gifski/issues/180 instead.