Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

After newest libgifski update the generator needs few seconds to start and the progress is laggy #95

Closed
sunshinejr opened this issue Jun 24, 2019 · 20 comments
Labels
bug Something isn't working help wanted Extra attention is needed

Comments

@sunshinejr
Copy link
Contributor

sunshinejr commented Jun 24, 2019

Issuehunt badges

The bounty here now applies to #180 instead.


This is the video I reproduced it with.

new_gifski_transitions.mov.zip


IssueHunt Summary

Backers (Total: $80.00)

Become a backer now!

Or submit a pull request to get the deposits!

Tips


IssueHunt has been backed by the following sponsors. Become a sponsor

@sindresorhus
Copy link
Owner

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?

@sunshinejr
Copy link
Contributor Author

sunshinejr commented Jun 24, 2019

I also noticed that most of the time when cancelling the conversion it will crash.

@kornelski
Copy link
Collaborator

What's the order of calls to the library? Are you setting the write callback before the frames?

@sindresorhus
Copy link
Owner

Yes:

gifski.setWriteCallback(context: &gifData) { bufferLength, bufferPointer, context in

@sindresorhus sindresorhus added bug Something isn't working help wanted Extra attention is needed labels Jul 1, 2019
@issuehunt-oss issuehunt-oss bot added the 💵 Funded on Issuehunt This issue has been funded on Issuehunt label Jul 2, 2019
@issuehunt-oss
Copy link

issuehunt-oss bot commented Jul 2, 2019

@issuehunt has funded $80.00 to this issue.


@sunshinejr
Copy link
Contributor Author

sunshinejr commented Jul 18, 2019

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:
frame1

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.

@ghost
Copy link

ghost commented Jul 22, 2019

Time profiler

Release 1.7.0

Screenshot 2019-07-22 at 12 13 55

Release 1.8.0

Screenshot 2019-07-22 at 11 31 58

It's clear the function 'addFrame' is taking orders of magnitude longer for the first several frames.

@ghost
Copy link

ghost commented Jul 22, 2019

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.

@sunshinejr
Copy link
Contributor Author

@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!

@kornelski
Copy link
Collaborator

kornelski commented Jul 22, 2019

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.

@ghost
Copy link

ghost commented Jul 22, 2019

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?

@sunshinejr
Copy link
Contributor Author

sunshinejr commented Jul 26, 2019

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.

@sunshinejr
Copy link
Contributor Author

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.

@sindresorhus
Copy link
Owner

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 28be9dc, I had to wrap the generator.generateCGImagesAsynchronously callback in DispatchQueue.global().async.

@kornelski
Copy link
Collaborator

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.

@kornelski
Copy link
Collaborator

In 6f6bf34 I've added another warning in case things were called out of order.

@ghost
Copy link

ghost commented Aug 15, 2019

@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...

Screenshot 2019-08-15 at 07 05 39

Happened when pressing cancel.

I'm checked out at 6f6bf34

@sunshinejr
Copy link
Contributor Author

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.

@ghost
Copy link

ghost commented Aug 15, 2019

No worries. I have provided a fix #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.

@sindresorhus sindresorhus removed the 💵 Funded on Issuehunt This issue has been funded on Issuehunt label Mar 11, 2020
@sindresorhus
Copy link
Owner

Closing as I don't think this is a problem anymore. The bounty here now applies to #180 instead.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working help wanted Extra attention is needed
Projects
None yet
Development

No branches or pull requests

3 participants