[Bug] Serious degrade of text updating in CodeEditorComponent/AsyncUpdater JUCE8

I just noticed this problem with JUCE 8.0.3 (MacOS, BigSur, Intel).

I use a CodeEditorComponent as a sort of debugging message window.

In JUCE 7, you can literally print a message every 1 ms and it prints them all extremely smoothly, one by one, scrolling without any jerking or halting.

In JUCE 8, it jerks and halts and falls behind.

Here is a test app demonstrating the issue:

CodeEditorTest.zip (14.8 KB)

It uses a HighResolutionTimer to create a String with a timestamp every 1 ms, and the Strings are then concatenated into blocks of text that are updated to the CodeEditorComponent using AsyncUpdater.

Here is a movie showing a side-by-side comparison of JUCE 7.0.12 (left) and JUCE 8.0.3 (right).


As you can see, JUCE 7 is scrolling smoothly and printing every single message one by one. JUCE 8 is jerking and halting and printing blocks.

The JUCE 8 version also gets “behind” and can’t keep up - if you let it run for awhile, then turn it off (by clicking the On/Off button), it keeps going for awhile. The JUCE 7 version stops instantly because it is keeping up with real time.

So I don’t know if this is a problem with the new Glyph handling code of JUCE 8, or some problem with the AsyncUpdater, or the CodeEditorComponent, or something else.

(Is there anything in JUCE 8 that is limiting the frequency with which AsyncUpdater issues the handleAsyncUpdate callback?)

Here is the relevant code (from the test app) that formats and prints the text - in case there’s something wrong with it. But this has been working smoothly for years, and is based on discussions and info on this forum.

void MainComponent::hiResTimerCallback()
{
    double hiResTime = juce::Time::getMillisecondCounterHiRes();

    long inSeconds = (long) (hiResTime * .001);
    auto hours3   = ((int) (inSeconds / 3600)) % 24;
    auto minutes3 = ((int) (inSeconds / 60)) % 60;
    auto seconds3 = ((int) inSeconds) % 60;
    auto millis3  = ((int) (hiResTime) % 1000);
    auto micros3  = ((long long) (hiResTime * 1000) % 1000);      // can be out of range for int
    
    juce::String timeStamp;
    timeStamp = juce::String::formatted("%02d:%02d:%02d.%03d %03lld",
            hours3, minutes3, seconds3, millis3, micros3    );
    
    addMessage(timeStamp + " - " + juce::String(count++) + " Here is a big long message with a whole lotta text to be printed ");
}

void MainComponent::addMessage(juce::String messageText)
{
        // add the message string to the list of messages that need to be posted asynchronously
        // and trigger a call to AsyncUpdate
    {
        const juce::ScopedLock sl (messageListLock);
        messageList.add(messageText);
        triggerAsyncUpdate();   // all examples have this inside the lock, I don't know why
    }
}

void MainComponent::handleAsyncUpdate()
{
        // here we create an empty string array
        // lock the messageList and swap it with the empty one
        // therefore we empty the main list and now have a local copy of it
        // the lock prevents it from being altered while we are swapping it

    juce::StringArray messages;
    {
        const juce::ScopedLock sl (messageListLock);
        messages.swapWith (messageList);
    }
        // assemble a chunk of text containing strings followed by line returns
    juce::String messageText;
    for (auto& string : messages)
        messageText << string << "\n";
    
    // add the text or text chunk to the end of the messageDisplay
    messageDisplay->moveCaretToEnd(false);
    messageDisplay->insertTextAtCaret (messageText);
}

Some more data…

I replaced the concatenating of the message list in the handleAsyncUpdate() function with just printing out a timestamp of when handleAsyncUpdate() is called, to examine the frequency with which the callback is received.

So basically, a HighResolutionTimer is calling triggerAsyncUpdate() every 1ms, and then we see how often handleAsyncUpdate() is received.

That project is here:
CodeEditorTest2.zip (14.7 KB)

The number to look at here is the millisecond count, i.e.

07:35:30.630 477 
         ms  micro

JUCE 7 shows that the handleAsyncUpdate() callback is received nearly every millisecond. There are a few gaps I indicated of 3~5 ms. Given that the app is doing nothing else, this is the kind of performance I have had for years.

JUCE 7.0.12

07:50:23.607 960 handleAsyncUpdate
07:50:23.608 962 handleAsyncUpdate
3 ms gap
07:50:23.611 735 handleAsyncUpdate
07:50:23.611 958 handleAsyncUpdate
07:50:23.612 993 handleAsyncUpdate
07:50:23.613 965 handleAsyncUpdate
07:50:23.614 948 handleAsyncUpdate
07:50:23.615 958 handleAsyncUpdate
07:50:23.616 948 handleAsyncUpdate
07:50:23.617 956 handleAsyncUpdate
07:50:23.618 958 handleAsyncUpdate
07:50:23.619 961 handleAsyncUpdate
07:50:23.620 961 handleAsyncUpdate
07:50:23.621 963 handleAsyncUpdate
07:50:23.622 988 handleAsyncUpdate
07:50:23.623 981 handleAsyncUpdate
07:50:23.624 997 handleAsyncUpdate
5 ms gap
07:50:23.629 301 handleAsyncUpdate
07:50:23.629 974 handleAsyncUpdate
07:50:23.630 968 handleAsyncUpdate
07:50:23.631 952 handleAsyncUpdate
07:50:23.633 018 handleAsyncUpdate
07:50:23.634 023 handleAsyncUpdate
07:50:23.634 987 handleAsyncUpdate
07:50:23.635 977 handleAsyncUpdate
07:50:23.637 043 handleAsyncUpdate
07:50:23.637 985 handleAsyncUpdate
07:50:23.638 984 handleAsyncUpdate
07:50:23.639 983 handleAsyncUpdate
07:50:23.640 983 handleAsyncUpdate
07:50:23.641 994 handleAsyncUpdate
5 ms gap
07:50:23.646 112 handleAsyncUpdate
07:50:23.647 004 handleAsyncUpdate
07:50:23.648 036 handleAsyncUpdate
07:50:23.648 983 handleAsyncUpdate
07:50:23.649 995 handleAsyncUpdate

JUCE 8, on the other hand, shows frequent large gaps of 48 - 54 ms, where no callback is received.

JUCE 8.0.3

07:35:30.532 427 handleAsyncUpdate
07:35:30.532 934 handleAsyncUpdate
07:35:30.533 941 handleAsyncUpdate
07:35:30.534 924 handleAsyncUpdate
48 ms gap
07:35:30.581 226 handleAsyncUpdate
07:35:30.581 960 handleAsyncUpdate
07:35:30.582 919 handleAsyncUpdate
07:35:30.583 942 handleAsyncUpdate
07:35:30.584 980 handleAsyncUpdate
47 ms gap
07:35:30.630 477 handleAsyncUpdate
07:35:30.630 948 handleAsyncUpdate
07:35:30.631 958 handleAsyncUpdate
07:35:30.633 054 handleAsyncUpdate
07:35:30.633 932 handleAsyncUpdate
07:35:30.634 990 handleAsyncUpdate
54 ms gap
07:35:30.688 103 handleAsyncUpdate
07:35:30.689 017 handleAsyncUpdate
07:35:30.689 905 handleAsyncUpdate
07:35:30.690 902 handleAsyncUpdate
07:35:30.691 905 handleAsyncUpdate
07:35:30.692 908 handleAsyncUpdate
07:35:30.693 907 handleAsyncUpdate
07:35:30.694 900 handleAsyncUpdate
07:35:30.695 898 handleAsyncUpdate
07:35:30.696 905 handleAsyncUpdate
07:35:30.697 904 handleAsyncUpdate
07:35:30.698 904 handleAsyncUpdate
07:35:30.699 905 handleAsyncUpdate
07:35:30.700 905 handleAsyncUpdate
07:35:30.701 905 handleAsyncUpdate
47 ms gap
07:35:30.748 644 handleAsyncUpdate
07:35:30.748 979 handleAsyncUpdate
07:35:30.750 001 handleAsyncUpdate
07:35:30.750 934 handleAsyncUpdate
07:35:30.751 964 handleAsyncUpdate
07:35:30.797 727 handleAsyncUpdate
07:35:30.797 959 handleAsyncUpdate

The frequent large gaps, along with accumulation of 48-54 messages during those gaps (in the previous app example) lead to the jerky updating shown in the video.

Now, I know there’s no guarantee of how often handleAsyncUpdater will be called, but what this shows is there is some degradation between the performance of the AsyncUpdater between JUCE 8 and JUCE 7.

I’m not in anyway saying this is the right way to be using this; I’m just pointing out that it worked better in JUCE 7. And I seem to be noticing occasional lags in other things in my app that use the AsyncUpdater. I hope someone from the team can look at this, thanks!

I wonder if it’s not an AsyncUpdater issue, but a text rendering performance issue that adds up when rendering larger amounts of text.

I’ve been seeing 3-4x slowdowns of text rendering performance on JUCE 8.

Is the updater smooth and consistent when you render just a few characters? 1 message per ms is probably 16-32 messages per frame (depending on your fps), so each frame in your example is rendering quite a bit of text.

I thought that was a possibility at first, it may have something to do with it, but given the data in my last post, the large gaps in between receiving the handleAsyncUpdate() callback seem to be the issue here.

So I created a third project, available here, where I combined the last two examples:
CodeEditorTest3.zip (15.0 KB)

void MainComponent::hiResTimerCallback()
{
    juce::String messageText = getTimeStamp() + " - " + juce::String(count++);

    // add the message string to the list of messages that need to be posted asynchronously
    // and trigger a call to AsyncUpdate
    {
        const juce::ScopedLock sl (messageListLock);
        messageList.add(messageText);
        triggerAsyncUpdate();   // all examples have this inside the lock, I don't know why
    }
}

juce::String MainComponent::getTimeStamp()
{
    double hiResTime = juce::Time::getMillisecondCounterHiRes();

    long inSeconds = (long) (hiResTime * .001);
    auto hours   = ((int) (inSeconds / 3600)) % 24;
    auto minutes = ((int) (inSeconds / 60)) % 60;
    auto seconds = ((int) inSeconds) % 60;
    auto millis  = ((int) (hiResTime) % 1000);
    auto micros  = ((long long) (hiResTime * 1000) % 1000);      // can be out of range for int
    
    return juce::String::formatted("%02d:%02d:%02d.%03d %03lld",
            hours, minutes, seconds, millis, micros    );
}

void MainComponent::handleAsyncUpdate()
{
        // here we create an empty string array
        // lock the messageList and swap it with the empty one
        // therefore we empty the main list and now have a local copy of it
        // the lock prevents it from being altered while we are swapping it

    juce::StringArray messages;
    {
        const juce::ScopedLock sl (messageListLock);
        messages.swapWith (messageList);
    }
        // assemble a chunk of text containing strings followed by line returns
    juce::String messageText;
    for (auto& string : messages)
        messageText << string << "\n";

    // add a timestamp indicating this function was called
    messageText << getTimeStamp() << " handleAsyncUpdate\n";

    // add the text or text chunk to the end of the messageDisplay
    messageDisplay->moveCaretToEnd(false);
    messageDisplay->insertTextAtCaret (messageText);
}

I made the message being posted every 1 ms much less text (just the timestamp and the count), and then there is a message added to the list when the handleAsyncUpdate() callback is actually received.

The JUCE 7 version shows that the handleAsyncUpdate() is received nearly every ms, so nearly each message is able to be appended individually, so the scrolling of the list in real-time is smooth:

JUCE 7.0.12

00:19:56.017 653 - 0
00:19:56.017 736 handleAsyncUpdate
00:19:56.018 656 - 1
00:19:56.018 743 handleAsyncUpdate
00:19:56.019 656 - 2
00:19:56.019 744 handleAsyncUpdate
00:19:56.020 657 - 3
00:19:56.020 746 handleAsyncUpdate
00:19:56.021 663 - 4
00:19:56.021 752 handleAsyncUpdate
00:19:56.022 655 - 5
00:19:56.022 744 handleAsyncUpdate
00:19:56.023 634 - 6
00:19:56.024 628 - 7
00:19:56.024 938 handleAsyncUpdate
00:19:56.025 653 - 8
00:19:56.025 738 handleAsyncUpdate
00:19:56.026 643 - 9
00:19:56.026 725 handleAsyncUpdate
00:19:56.027 633 - 10
00:19:56.027 690 handleAsyncUpdate
00:19:56.028 645 - 11
00:19:56.028 701 handleAsyncUpdate
00:19:56.029 650 - 12
00:19:56.029 707 handleAsyncUpdate
00:19:56.030 649 - 13
00:19:56.030 705 handleAsyncUpdate
00:19:56.031 644 - 14
00:19:56.031 704 handleAsyncUpdate
00:19:56.032 631 - 15
00:19:56.032 730 handleAsyncUpdate
00:19:56.033 654 - 16
00:19:56.033 736 handleAsyncUpdate
00:19:56.034 658 - 17
00:19:56.034 741 handleAsyncUpdate
00:19:56.035 656 - 18
00:19:56.035 738 handleAsyncUpdate
00:19:56.036 647 - 19
00:19:56.036 703 handleAsyncUpdate
00:19:56.037 642 - 20
00:19:56.037 697 handleAsyncUpdate
00:19:56.038 657 - 21
00:19:56.038 713 handleAsyncUpdate
00:19:56.039 637 - 22
00:19:56.039 694 handleAsyncUpdate

The JUCE 8 version shows that there are a few callbacks received 1 ms apart, and then large gaps of time where nothing is received and a large number of messages accumulate.

JUCE 8.0.3

21:38:31.358 930 - 0
21:38:31.359 036 handleAsyncUpdate
21:38:31.359 931 - 1
21:38:31.360 008 handleAsyncUpdate
21:38:31.360 924 - 2
21:38:31.361 003 handleAsyncUpdate
21:38:31.361 924 - 3
21:38:31.362 926 - 4
21:38:31.363 929 - 5
21:38:31.364 929 - 6
21:38:31.365 928 - 7
21:38:31.366 923 - 8
21:38:31.367 924 - 9
21:38:31.368 925 - 10
21:38:31.369 927 - 11
21:38:31.370 924 - 12
21:38:31.371 919 - 13
21:38:31.372 921 - 14
21:38:31.373 922 - 15
21:38:31.374 920 - 16
21:38:31.375 922 - 17
21:38:31.376 921 - 18
21:38:31.377 924 - 19
21:38:31.378 920 - 20
21:38:31.379 926 - 21
21:38:31.380 887 handleAsyncUpdate
21:38:31.380 925 - 22
21:38:31.381 096 handleAsyncUpdate
21:38:31.381 919 - 23
21:38:31.381 990 handleAsyncUpdate
21:38:31.382 918 - 24
21:38:31.382 975 handleAsyncUpdate
21:38:31.383 922 - 25
21:38:31.383 992 handleAsyncUpdate
21:38:31.384 925 - 26
21:38:31.384 997 handleAsyncUpdate
21:38:31.385 917 - 27
21:38:31.385 975 handleAsyncUpdate
21:38:31.386 918 - 28
21:38:31.386 983 handleAsyncUpdate
21:38:31.387 920 - 29
21:38:31.387 977 handleAsyncUpdate
21:38:31.388 921 - 30
21:38:31.389 920 - 31
21:38:31.390 133 handleAsyncUpdate
21:38:31.390 921 - 32
21:38:31.390 989 handleAsyncUpdate
21:38:31.391 921 - 33
21:38:31.391 995 handleAsyncUpdate
21:38:31.392 917 - 34
21:38:31.392 969 handleAsyncUpdate
21:38:31.393 919 - 35
21:38:31.393 984 handleAsyncUpdate
21:38:31.394 927 - 36
21:38:31.395 921 - 37
21:38:31.396 919 - 38
21:38:31.397 922 - 39
21:38:31.398 921 - 40
21:38:31.399 924 - 41
21:38:31.400 921 - 42
21:38:31.401 921 - 43
21:38:31.402 920 - 44
21:38:31.403 921 - 45
21:38:31.404 924 - 46
21:38:31.405 919 - 47
21:38:31.406 923 - 48
21:38:31.407 923 - 49
21:38:31.408 922 - 50
21:38:31.409 922 - 51
21:38:31.410 920 - 52
21:38:31.411 922 - 53
21:38:31.412 924 - 54
21:38:31.413 923 - 55
21:38:31.414 925 - 56
21:38:31.415 920 - 57
21:38:31.416 921 - 58
21:38:31.417 919 - 59
21:38:31.418 921 - 60
21:38:31.419 922 - 61
21:38:31.420 923 - 62
21:38:31.421 923 - 63
21:38:31.422 926 - 64
21:38:31.423 924 - 65
21:38:31.424 921 - 66
21:38:31.425 924 - 67
21:38:31.426 925 - 68
21:38:31.427 925 - 69
21:38:31.428 926 - 70
21:38:31.429 916 - 71
21:38:31.430 914 - 72
21:38:31.431 916 - 73
21:38:31.432 921 - 74
21:38:31.433 925 - 75
21:38:31.434 925 - 76
21:38:31.435 924 - 77
21:38:31.436 921 - 78
21:38:31.437 917 - 79
21:38:31.438 921 - 80
21:38:31.439 924 - 81
21:38:31.440 925 - 82
21:38:31.441 923 - 83
21:38:31.442 919 - 84
21:38:31.443 918 - 85
21:38:31.444 927 - 86
21:38:31.445 928 - 87
21:38:31.446 926 - 88
21:38:31.447 921 - 89
21:38:31.448 922 - 90
21:38:31.449 930 - 91
21:38:31.450 920 - 92
21:38:31.451 923 - 93
21:38:31.452 923 - 94
21:38:31.453 926 - 95
21:38:31.454 925 - 96
21:38:31.455 923 - 97
21:38:31.456 921 - 98
21:38:31.457 923 - 99
21:38:31.458 927 - 100
21:38:31.459 921 - 101
21:38:31.460 922 - 102
21:38:31.461 924 - 103
21:38:31.462 922 - 104
21:38:31.463 928 - 105
21:38:31.464 920 - 106
21:38:31.465 920 - 107
21:38:31.466 922 - 108
21:38:31.467 923 - 109
21:38:31.468 925 - 110
21:38:31.469 922 - 111
21:38:31.470 923 - 112
21:38:31.471 918 - 113
21:38:31.472 921 - 114
21:38:31.473 921 - 115
21:38:31.474 923 - 116
21:38:31.475 922 - 117
21:38:31.476 924 - 118
21:38:31.477 926 - 119
21:38:31.478 923 - 120
21:38:31.479 919 - 121
21:38:31.480 921 - 122
21:38:31.481 928 - 123
21:38:31.482 093 handleAsyncUpdate
21:38:31.482 923 - 124

Then the whole chunk of accumulated messages gets inserted at one time, causing the jerky and halting updating seen in video at the top.

So with JUCE 8, there are large interruptions in receiving the handleAsyncUpdate() callback.

1 Like

I have also seen this behavior with version 8.0.3. Reverting to v7 for now…

1 Like

Please can you provide some more information? What behaviour exactly are you seeing? Are you using the same mechanism (HighResTimer driving an AsyncUpdater which prints into a TextEditor), or something else?

What I’m doing is very similar but not exactly the same.
It does relate to printing to a TextEditor component but I’m not using handleAsyncUpdate() and I’m using the standard timerCallback() not highRes.

I Convert MIDI input to text, fill a buffer with text Strings, unwind the buffer with the TimerCallback() every 1ms, then print them to a textEditor window. In version 8.03 the prints slowed way down. Same code works fine in v7.

1 Like

Not to throw a wrench into this discussion, but I decided to see if this would work better with a Timer, than AsyncUpdater.

I really don’t understand what I’m seeing.

All I am doing here is calling a Timer every 10 ms, and then printing out a timestamp of when the timerCallback occurs.

In JUCE 7, the callbacks occur with elapsed times between them of approximately 5~15 ms.

JUCE 7.0.12

00:07:23.321 663 timerCallback, elapsed 00:00:00.014 686 - 14 ms
00:07:23.328 060 timerCallback, elapsed 00:00:00.006 396 - 6 ms
00:07:23.338 403 timerCallback, elapsed 00:00:00.010 343 - 10 ms
00:07:23.347 810 timerCallback, elapsed 00:00:00.009 406 - 9 ms
00:07:23.359 500 timerCallback, elapsed 00:00:00.011 689 - 11 ms
00:07:23.372 375 timerCallback, elapsed 00:00:00.012 875 - 12 ms
00:07:23.380 880 timerCallback, elapsed 00:00:00.008 505 - 8 ms
00:07:23.390 343 timerCallback, elapsed 00:00:00.009 462 - 9 ms
00:07:23.405 149 timerCallback, elapsed 00:00:00.014 806 - 14 ms
00:07:23.410 729 timerCallback, elapsed 00:00:00.005 579 - 5 ms
00:07:23.421 797 timerCallback, elapsed 00:00:00.011 068 - 11 ms
00:07:23.430 300 timerCallback, elapsed 00:00:00.008 502 - 8 ms
00:07:23.440 922 timerCallback, elapsed 00:00:00.010 621 - 10 ms
00:07:23.455 554 timerCallback, elapsed 00:00:00.014 631 - 14 ms
00:07:23.461 246 timerCallback, elapsed 00:00:00.005 692 - 5 ms
00:07:23.473 636 timerCallback, elapsed 00:00:00.012 389 - 12 ms
00:07:23.488 600 timerCallback, elapsed 00:00:00.014 963 - 14 ms
00:07:23.495 738 timerCallback, elapsed 00:00:00.007 138 - 7 ms
00:07:23.506 964 timerCallback, elapsed 00:00:00.011 226 - 11 ms
00:07:23.522 907 timerCallback, elapsed 00:00:00.015 942 - 15 ms
00:07:23.526 401 timerCallback, elapsed 00:00:00.003 494 - 3 ms

In JUCE 8, I get a very strange output that starts out similar, but then turns into alternating elapsed times between 0~84 ms.

JUCE 8.0.3

00:14:49.654 284 timerCallback, elapsed 00:00:00.015 629 - 15 ms
00:14:49.660 709 timerCallback, elapsed 00:00:00.006 425 - 6 ms
00:14:49.673 744 timerCallback, elapsed 00:00:00.013 034 - 13 ms
00:14:49.689 036 timerCallback, elapsed 00:00:00.015 291 - 15 ms
00:14:49.694 294 timerCallback, elapsed 00:00:00.005 258 - 5 ms
00:14:49.706 950 timerCallback, elapsed 00:00:00.012 655 - 12 ms
00:14:49.718 493 timerCallback, elapsed 00:00:00.011 543 - 11 ms
00:14:49.804 300 timerCallback, elapsed 00:00:00.085 807 - 85 ms
00:14:49.804 564 timerCallback, elapsed 00:00:00.000 264 - 0 ms
00:14:49.886 819 timerCallback, elapsed 00:00:00.082 254 - 82 ms
00:14:49.886 998 timerCallback, elapsed 00:00:00.000 178 - 0 ms
00:14:49.969 333 timerCallback, elapsed 00:00:00.082 335 - 82 ms
00:14:49.969 517 timerCallback, elapsed 00:00:00.000 183 - 0 ms
00:14:50.053 782 timerCallback, elapsed 00:00:00.084 264 - 84 ms
00:14:50.053 966 timerCallback, elapsed 00:00:00.000 183 - 0 ms
00:14:50.136 089 timerCallback, elapsed 00:00:00.082 123 - 82 ms
00:14:50.136 308 timerCallback, elapsed 00:00:00.000 218 - 0 ms
00:14:50.220 276 timerCallback, elapsed 00:00:00.083 967 - 83 ms
00:14:50.220 470 timerCallback, elapsed 00:00:00.000 194 - 0 ms
00:14:50.303 846 timerCallback, elapsed 00:00:00.083 375 - 83 ms
00:14:50.304 134 timerCallback, elapsed 00:00:00.000 288 - 0 ms
00:14:50.388 589 timerCallback, elapsed 00:00:00.084 454 - 84 ms
00:14:50.388 803 timerCallback, elapsed 00:00:00.000 214 - 0 ms
00:14:50.470 692 timerCallback, elapsed 00:00:00.081 889 - 81 ms
00:14:50.470 907 timerCallback, elapsed 00:00:00.000 214 - 0 ms
00:14:50.553 486 timerCallback, elapsed 00:00:00.082 579 - 82 ms
00:14:50.553 712 timerCallback, elapsed 00:00:00.000 226 - 0 ms
00:14:50.638 764 timerCallback, elapsed 00:00:00.085 051 - 85 ms
00:14:50.638 964 timerCallback, elapsed 00:00:00.000 199 - 0 ms
00:14:50.722 107 timerCallback, elapsed 00:00:00.083 142 - 83 ms
00:14:50.722 353 timerCallback, elapsed 00:00:00.000 246 - 0 ms
00:14:50.804 076 timerCallback, elapsed 00:00:00.081 723 - 81 ms

The project for this is here:
CodeEditorTest4.zip (13.2 KB)

Unless I’m crazy and doing something really wrong. But this is the timerCallback:

private:
    class TimerUpdater : public juce::Timer
    {
    public:
        TimerUpdater(MainComponent& mainIn)
        : main (mainIn) {}
        
    private:
        virtual void timerCallback() override
        {
            auto nowTime = juce::Time::getMillisecondCounterHiRes();
            auto elapsed = nowTime - lastTime;
            lastTime = nowTime;
            auto millis  = ((int) (elapsed) % 1000);

            // add a timestamp indicating this function was called
            juce::String messageText;
            messageText << main.getTimeStamp(nowTime) << " timerCallback, elapsed " << main.getTimeStamp(elapsed) << " - " << juce::String(millis) <<" ms\n";

            // add the text or text chunk to the end of the messageDisplay
            main.messageDisplay->moveCaretToEnd(false);
            main.messageDisplay->insertTextAtCaret (messageText);
        }
        MainComponent& main;
        double lastTime;

EDIT:

Not to mention… if I happen to be running another program on this laptop, that uses > 150% or so of 1 CPU, the time between callbacks in the JUCE 8 version increases quite a bit, while the JUCE 7-compiled version does not.

JUCE 8.0.3

00:26:31.887 431 timerCallback, elapsed 00:00:00.138 541 - 138 ms
00:26:31.887 763 timerCallback, elapsed 00:00:00.000 332 - 0 ms
00:26:31.898 105 timerCallback, elapsed 00:00:00.010 341 - 10 ms
00:26:32.034 466 timerCallback, elapsed 00:00:00.136 361 - 136 ms
00:26:32.167 861 timerCallback, elapsed 00:00:00.133 394 - 133 ms
00:26:32.168 182 timerCallback, elapsed 00:00:00.000 320 - 0 ms
00:26:32.179 208 timerCallback, elapsed 00:00:00.011 026 - 11 ms
00:26:32.315 768 timerCallback, elapsed 00:00:00.136 559 - 136 ms
00:26:32.316 077 timerCallback, elapsed 00:00:00.000 309 - 0 ms
00:26:32.450 443 timerCallback, elapsed 00:00:00.134 365 - 134 ms
00:26:32.450 788 timerCallback, elapsed 00:00:00.000 344 - 0 ms
00:26:32.582 202 timerCallback, elapsed 00:00:00.131 414 - 131 ms
00:26:32.582 531 timerCallback, elapsed 00:00:00.000 328 - 0 ms
00:26:32.720 748 timerCallback, elapsed 00:00:00.138 216 - 138 ms
00:26:32.721 070 timerCallback, elapsed 00:00:00.000 322 - 0 ms
00:26:32.731 187 timerCallback, elapsed 00:00:00.010 116 - 10 ms
00:26:32.865 699 timerCallback, elapsed 00:00:00.134 511 - 134 ms
00:26:32.866 031 timerCallback, elapsed 00:00:00.000 332 - 0 ms

The team’s been busy with the Audio Developer Conference recently, and we’re just catching up with the new forum activity now. This issue is on our radar, and I hope we’ll be able to investigate and address it shortly. However, there’s also a few other high-priority issues that we need to investigate, so it might be a little while before we are able to publish a fix.

1 Like

We have pretty severe issues with text rendering performance also.
Both Mac 12.5.1 and Win10 have shown the problem with juce 8.

Here’s a simple demo project showing the difference.
Use mouse wheel to zoom the view in and out.
Switch your juce global paths between j6/7 and j8 and it will be immediately obvious.

Also, note this other thread: JUCE 8 Text rendering performance - #2 by cxhawk

textRenderDemo 2.zip (19.8 KB)

I hate to be a “bumper”, but just want to check @reuk et al saw the example project we posted above.

The text rendering performance is rendering j8 a non-starter for us.

I’d like to mention that my MAIN concern in this thread is not so much the inability to rapidly scroll text in a CodeEditor, but the seemingly degraded performance of the AsyncUpdater and Timer that I demonstrated between JUCE 7 and JUCE 8. Thanks.

@thecargocult I think I have a fix for the problem you’re reporting, at least based on the example code you’ve shared. I’ll get something up ASAP. That being said I think there are ways you could have optimised it without changes to JUCE.

@stephenk are you saying you can see this is a console app or without a GUI and you’re just printing statements from the callback? If not I still strongly suspect this is a TextEditor (CodeEditor) issue. Work on this is currently in progress but the work is non-trivial.

It’s not actual production code… it’s just proving the point that text rendering has an issue since j8. Thanks for taking a look

@thecargocult thanks for sharing your example project it has help me find some hot spots that are probably worth improving but I don’t think we can easily catch all the cases that your zooming example creates. However, there’s likely still a way for you to improve performance.

The expensive bit is reshaping the text, and this is just going to be more expensive than it used to be in order to deal with fallback fonts, ligatures, and all the other stuff that comes with unicode support.

Every time you change the font size, or the bounding box, there is a potential it needs reshaping. However, in your specific case, because the aspect ratio of everything stays the same we could avoid reshaping. Unfortunately at the point the caching happens this is hard to detect. Not impossible, but it does increase complexity and I suspect I’m hitting floating point precision issues in some cases.

However, at the level you’re writing your code you know this information explicitly and can deal with this by using an AffineTransform. This also significantly reduces the complexity in your own code. For example your paint function can now be as follows…

void MainComponent::paint(juce::Graphics& g)
{
    g.fillAll(getLookAndFeel().findColour(juce::ResizableWindow::backgroundColourId));

    {
        juce::Graphics::ScopedSaveState scopedSaveState (g);
        g.addTransform (juce::AffineTransform::scale (zoomFactor));
        g.addTransform (juce::AffineTransform::translation (-viewPosition.x, -viewPosition.y));

        // Calculate grid dimensions based on window at zoom level 1.0
        const float baseWidth = (float)getWidth();
        const float baseHeight = (float)getHeight();
        const float aspectRatio = baseWidth / baseHeight;
        const int numColumns = (int)std::sqrt(labels.size() * aspectRatio);
        const int numRows = (labels.size() + numColumns - 1) / numColumns;

        // Add 30% spacing to cells
        const float baseCellWidth = (baseWidth / numColumns) * 0.7f;
        const float baseCellHeight = (baseHeight / numRows) * 0.7f;
        const float cellSpacingX = (baseWidth / numColumns) * 0.3f;
        const float cellSpacingY = (baseHeight / numRows) * 0.3f;

        g.setFont(std::min(baseCellWidth, baseCellHeight) * 0.4f);
        g.setColour(juce::Colours::white);

        // Calculate visible range in cell coordinates
        const float cellTotalWidth = baseCellWidth + cellSpacingX;
        const float cellTotalHeight = baseCellHeight + cellSpacingY;

        // Draw visible labels
        for (int row = 0; row < numRows; ++row)
        {
            for (int col = 0; col < numColumns; ++col)
            {
                const int index = row * numColumns + col;
                if (index < labels.size())
                {
                    // Calculate base position including spacing
                    const float x = col * cellTotalWidth;
                    const float y = row * cellTotalHeight;

                    g.drawText(labels[index],
                        x, y,
                        baseCellWidth,
                        baseCellHeight,
                        juce::Justification::centred);
                }
            }
        }
    }

    g.setFont(12.0f);
    g.setColour(juce::Colours::white.withAlpha(0.8f));
    g.drawText(versionString,
        getWidth() - 100, 0,
        95, 20,
        juce::Justification::centredRight);
}

The key things to note are

  • The removal of any references to viewPosition or zoomFactor in any of the calculations
  • The addition of a scale and translation transform
  • The ScopedSaveState that will ensure the transforms are only applied to the area being zoomed, and restore the state in order to draw the stationary text
  • No handling of text that is offscreen, that is already optimised by JUCE

Is this something that could apply to your production code too?

If you can apply this and still find you’re hitting up against performance issues, let me know because I think I can see other reasons you could be hitting issues that aren’t captured in your example.

Hope that helps.

@thecargocult I’ve pushed an optimisation to develop that aims to improve things if just the position of some text moves or if you have the same text in lots of different positions. Unfortunately optimising when the size of text changes just doesn’t make sense as some fonts may even change shape as the size changes. So in the case of zooming I would recommend using the AffineTransform as suggested above. You can also use it for position but after this commit I don’t expect you would see any performance advantage in doing so.

No. Could you please check my posts again? I think my examples are fairly clear. There are four different uploaded GUI app projects you can look at.

I suspect that myself and the other person are talking about two different issues here in this thread.

In my case, the problem is the AsyncUpdater callbacks are received very far apart in JUCE 8, and not so in JUCE 7, even though they are being triggered every 1 ms. This leads to jerky text printing since it’s printing whole blocks of messages instead of one or two lines at a time. I then switched it to a Timer, and the performance of the Timer in JUCE 8 is radically worse than in JUCE 7. I demonstrated that with one of the projects.

here’s the post about the Timer:

Here’s the post about the AsyncUpdater:

EDIT: In summary, I don’t think the issue I demonstrated necessarily has anything to do with the CodeEditor or the text drawing, but rather the AsyncUpdater and Timer Performance…

Sorry for hijackling.
I’ll start a new thread.

@stephenk if I test the AsyncUpdater in isolation without involving a CodeEditor, or really any GUI components, if I call hiResTimerCallback() at 1 ms intervals with a call to triggerAsyncUpdate(), after a little bit of settling I get around 970-980 calls to handleAsyncUpdate() per second.

handleAsyncUpdate() and timerCallback() are called on the Message thread which is also where the GUI is rendering, if the message thread is doing more work (as it is with the CodeEditor in JUCE 8) the less of those callbacks will be delivered.

The main reason for this extra work in JUCE 8 is the text shaping in order to have better font and unicode support. We are currently working on changes to the TextEditor that should bring improvements that will likely trickle down to the CodeEditor too. However, blasting it with lots of different strings at a rate of 1000 times second is likely to always be a little slower as it makes it very difficult to make effective of use of a cache!

The docs to for the Timer make it quite clear about what sort of rate of callbacks you can expect…

The time interval isn’t guaranteed to be precise to any more than maybe 10-20ms, and the intervals may end up being much longer than requested if the system is busy.

The triggerAsyncUpdate() also says this…

If an update callback is already pending but hasn’t happened yet, calling this method will have no effect.

So while the UI is busy shaping the text further calls to triggerAsyncUpdate() will be getting discarded. I think this is what you are seeing.

This is very different to the hiResTimerCallback() which happens on a completely independent thread (which is also high priority).

You seem to be implying that “of course this would over-tax the system!” - yet that used to work really fine in JUCE 7.

There really seems to be something else involved here, not just changes to glyph rendering.

Take a look at this code being output from my CodeEditorTest3 project (above), on JUCE 8:

The String with the number at the end is being created every ms by the HiRes thread. Then a single TriggerAsyncUpdate is called, and we print the String when the callback is received:

00:05:37.473 032 - 3550
00:05:37.473 095 handleAsyncUpdate
00:05:37.474 033 - 3551
00:05:37.474 073 handleAsyncUpdate
00:05:37.475 032 - 3552
00:05:37.475 070 handleAsyncUpdate
00:05:37.476 029 - 3553
00:05:37.476 068 handleAsyncUpdate
00:05:37.477 028 - 3554
00:05:37.477 062 handleAsyncUpdate
00:05:37.478 034 - 3555
00:05:37.478 081 handleAsyncUpdate
00:05:37.479 030 - 3556
00:05:37.479 070 handleAsyncUpdate
00:05:37.480 035 - 3557
00:05:37.480 097 handleAsyncUpdate
00:05:37.481 030 - 3558
00:05:37.481 068 handleAsyncUpdate
00:05:37.482 031 - 3559
00:05:37.482 074 handleAsyncUpdate
00:05:37.483 029 - 3560
00:05:37.484 029 - 3561
00:05:37.485 053 - 3562
00:05:37.486 032 - 3563
00:05:37.487 034 - 3564
00:05:37.488 030 - 3565
00:05:37.489 029 - 3566
00:05:37.490 028 - 3567
00:05:37.491 029 - 3568
00:05:37.492 031 - 3569
00:05:37.493 029 - 3570
00:05:37.494 027 - 3571
00:05:37.495 030 - 3572
00:05:37.496 030 - 3573
00:05:37.497 029 - 3574
00:05:37.498 029 - 3575
00:05:37.499 028 - 3576
00:05:37.500 028 - 3577
00:05:37.501 027 - 3578
00:05:37.502 030 - 3579
00:05:37.503 029 - 3580
00:05:37.504 026 - 3581
00:05:37.505 027 - 3582
00:05:37.506 032 - 3583
00:05:37.507 027 - 3584
00:05:37.508 031 - 3585
00:05:37.509 032 - 3586
00:05:37.510 030 - 3587
00:05:37.511 031 - 3588
00:05:37.512 033 - 3589
00:05:37.513 034 - 3590
00:05:37.514 035 - 3591
00:05:37.515 032 - 3592
00:05:37.516 030 - 3593
00:05:37.517 029 - 3594
00:05:37.518 030 - 3595
00:05:37.519 028 - 3596
00:05:37.520 030 - 3597
00:05:37.521 032 - 3598
00:05:37.522 031 - 3599
00:05:37.523 029 - 3600
00:05:37.524 030 - 3601
00:05:37.524 175 handleAsyncUpdate
00:05:37.525 030 - 3602
00:05:37.525 079 handleAsyncUpdate
00:05:37.526 029 - 3603
00:05:37.526 069 handleAsyncUpdate
00:05:37.527 031 - 3604
00:05:37.527 071 handleAsyncUpdate
00:05:37.528 030 - 3605
00:05:37.528 075 handleAsyncUpdate
00:05:37.529 029 - 3606
00:05:37.529 087 handleAsyncUpdate
00:05:37.530 028 - 3607
00:05:37.530 056 handleAsyncUpdate
00:05:37.531 031 - 3608
00:05:37.531 069 handleAsyncUpdate
00:05:37.532 030 - 3609
00:05:37.532 066 handleAsyncUpdate
00:05:37.533 035 - 3610
00:05:37.533 079 handleAsyncUpdate

As you can see, it handles each line, every 1 ms, perfectly fine (for awhile) and then there’s a large gap of time where no callbacks are received. Why would that happen? Certainly not from creating the text to draw, because why can it do 15 or 20 lines perfectly fine, then take a huge amount of time to do “something” ? All the lines are the same length basically…

This is very cyclic; I won’t paste it here, but it repeats. if you let the app run, you will see something like this:

22 callbacks received 1 ms apart
A large gap of 42 ms with no callbacks
26 callbacks received 1 ms apart
A large gap of 41 ms with no callbacks
23 callbacks received 1 ms apart
A large gap of 43 ms with no callbacks
… and so on.

Secondly, this is output from the CodeEditorTest4 project above, using a Timer. This does nothing but print a String when the Timer Callback is received, and the Timer is running at 10 ms.

Here we see the expected performance as stated by the docs:

JUCE 7:

00:19:24.968 656 timerCallback, elapsed 00:00:00.010 764 - 10 ms
00:19:24.980 911 timerCallback, elapsed 00:00:00.012 254 - 12 ms
00:19:24.992 023 timerCallback, elapsed 00:00:00.011 112 - 11 ms
00:19:25.003 029 timerCallback, elapsed 00:00:00.011 005 - 11 ms
00:19:25.013 656 timerCallback, elapsed 00:00:00.010 627 - 10 ms
00:19:25.025 739 timerCallback, elapsed 00:00:00.012 082 - 12 ms
00:19:25.037 814 timerCallback, elapsed 00:00:00.012 075 - 12 ms
00:19:25.049 951 timerCallback, elapsed 00:00:00.012 137 - 12 ms
00:19:25.060 729 timerCallback, elapsed 00:00:00.010 777 - 10 ms
00:19:25.072 831 timerCallback, elapsed 00:00:00.012 102 - 12 ms
00:19:25.084 036 timerCallback, elapsed 00:00:00.011 204 - 11 ms
00:19:25.093 896 timerCallback, elapsed 00:00:00.009 860 - 9 ms
00:19:25.104 935 timerCallback, elapsed 00:00:00.011 038 - 11 ms
00:19:25.115 730 timerCallback, elapsed 00:00:00.010 794 - 10 ms

Here we see something a whole lot different:

JUCE 8:

00:19:29.353 735 timerCallback, elapsed 00:00:00.000 193 - 0 ms
00:19:29.365 924 timerCallback, elapsed 00:00:00.012 188 - 12 ms
00:19:29.376 886 timerCallback, elapsed 00:00:00.010 962 - 10 ms
00:19:29.453 257 timerCallback, elapsed 00:00:00.076 370 - 76 ms
00:19:29.453 461 timerCallback, elapsed 00:00:00.000 203 - 0 ms
00:19:29.465 871 timerCallback, elapsed 00:00:00.012 409 - 12 ms
00:19:29.476 029 timerCallback, elapsed 00:00:00.010 158 - 10 ms
00:19:29.555 653 timerCallback, elapsed 00:00:00.079 623 - 79 ms
00:19:29.555 876 timerCallback, elapsed 00:00:00.000 223 - 0 ms
00:19:29.568 375 timerCallback, elapsed 00:00:00.012 498 - 12 ms
00:19:29.580 725 timerCallback, elapsed 00:00:00.012 349 - 12 ms
00:19:29.655 535 timerCallback, elapsed 00:00:00.074 810 - 74 ms
00:19:29.655 737 timerCallback, elapsed 00:00:00.000 202 - 0 ms
00:19:29.667 886 timerCallback, elapsed 00:00:00.012 148 - 12 ms
00:19:29.678 558 timerCallback, elapsed 00:00:00.010 672 - 10 ms
00:19:29.754 974 timerCallback, elapsed 00:00:00.076 415 - 76 ms

Is this really all just because of changes in font rendering? That is what is skewing the times between the Timer Callbacks?