Flash Template Freeze

#1
Hi there !

(sorry for my poor english, thx Google Translate !)

I have been working on Caspar 2.0.7 (stable) for over a year, on several projects. On one of these projects, I have a mysterious bug.

I developed a custom client with Air, which connects to Caspar with the AS3 framework.
Caspar loads two flash templates positioned on different video layers, with in between a video layer. The templates communicate with the client via local socket.
The client is identical for all projects, and flash templates use common code as well.

The problem project is the only one that uses two flash templates.

Result: after a few minutes, or a few hours, the rendering of the flash template above freeze.

The flash always responds (tested with MonsterDebugger for example), so the process is OK, but the rendering remains frozen. The second flash template remains animated.

Here the Caspar config :

Code: Select all

<?xml version="1.0" encoding="utf-8" standalone="yes"?>
<configuration>
  <paths>
    <media-path>C:\Users\ddesjardin\Desktop\SVX2Flash\bin</media-path>
    <log-path>log\</log-path>
    <data-path>data\</data-path>
    <template-path>C:\Users\ddesjardin\Desktop\SVX2Flash\bin</template-path>
    <thumbnails-path>thumbnails\</thumbnails-path>
  </paths>
  <log-level>debug</log-level>
  <mixer>
    <blend-modes>true</blend-modes>
    <straight-alpha>true</straight-alpha>
    <chroma-key>true</chroma-key>
  </mixer>
  <thumbnails>
    <generate-thumbnails>false</generate-thumbnails>
  </thumbnails>
  <channels>
    <channel>
      <video-mode>PAL</video-mode>
      <straight-alpha-output>true</straight-alpha-output>
      <consumers>
        <screen>
          <device>2</device>
          <name>OUTOUT</name>
          <borderless>true</borderless>
        </screen>
      </consumers>
    </channel>
  </channels>
  <controllers>
    <tcp>
      <port>5250</port>
      <protocol>AMCP</protocol>
    </tcp>
  </controllers>
</configuration>
Here the log :

Code: Select all

[2017-09-07 17:58:24.650] [8460] [info]    ############################################################################
[2017-09-07 17:58:24.651] [8460] [info]    CasparCG Server is distributed by the Swedish Broadcasting Corporation (SVT)
[2017-09-07 17:58:24.651] [8460] [info]    under the GNU General Public License GPLv3 or higher.
[2017-09-07 17:58:24.651] [8460] [info]    Please see LICENSE.TXT for details.
[2017-09-07 17:58:24.651] [8460] [info]    http://www.casparcg.com/
[2017-09-07 17:58:24.651] [8460] [info]    ############################################################################
[2017-09-07 17:58:24.651] [8460] [info]    Starting CasparCG Video and Graphics Playout Server 2.0.7.e9fc25a Stable
[2017-09-07 17:58:24.651] [8460] [info]    on Windows 8.1 Pro 
[2017-09-07 17:58:24.651] [8460] [info]    Intel(R) Core(TM) i7-3770 CPU @ 3.40GHz Physical Threads: 8
[2017-09-07 17:58:24.651] [8460] [info]    XPS 8500
[2017-09-07 17:58:24.656] [8460] [info]    Decklink 10.7.1
[2017-09-07 17:58:24.657] [8460] [info]    Bluefish Not found
[2017-09-07 17:58:24.659] [8460] [info]    FreeImage 3.15.4
[2017-09-07 17:58:24.659] [8460] [info]    FFMPEG-avcodec 55.52.102
[2017-09-07 17:58:24.659] [8460] [info]    FFMPEG-avformat 55.33.100
[2017-09-07 17:58:24.659] [8460] [info]    FFMPEG-avfilter 4.2.100
[2017-09-07 17:58:24.659] [8460] [info]    FFMPEG-avutil 52.66.100
[2017-09-07 17:58:24.659] [8460] [info]    FFMPEG-swscale 2.5.102
[2017-09-07 17:58:24.659] [8460] [info]    Flash 26.0.0.151
[2017-09-07 17:58:24.661] [8460] [info]    flash[cg20.fth.pal|0] Initialized.
[2017-09-07 17:58:24.661] [8460] [info]    flash[cg20.fth.pal|0] Invoking info-command: <invoke name="GetInfo" returntype="xml"><arguments></arguments></invoke>
[2017-09-07 17:58:24.752] [4248] [debug]   flash-player[cg20.fth.pal|1024x576] [command]      <invoke name="OnCommand" returntype="xml"><arguments><string>Command recieved @GetInfo@?@</string></arguments></invoke>
[2017-09-07 17:58:24.782] [4248] [info]    flash-player[cg20.fth.pal|1024x576] Initialized.
[2017-09-07 17:58:24.783] [4248] [debug]   flash-player[cg20.fth.pal|1024x576] [command]      <invoke name="OnCommand" returntype="xml"><arguments><string>Command recieved @GetInfo@?@</string></arguments></invoke>
[2017-09-07 17:58:24.861] [8460] [trace]   Template-Host 2.0.4.3803 RC
[2017-09-07 17:58:24.862] [8460] [info]    NewTek iVGA unavailable (Processing.AirSend.x86.dll)
[2017-09-07 17:58:24.862] [8460] [info]    casparcg.config:
-----------------------------------------
<?xml version="1.0" encoding="utf-8"?>
<configuration>
   <paths>
      <media-path>C:\Users\ddesjardin\Desktop\SVX2Flash\bin</media-path>
      <log-path>log\</log-path>
      <data-path>data\</data-path>
      <template-path>C:\Users\ddesjardin\Desktop\SVX2Flash\bin</template-path>
      <thumbnails-path>thumbnails\</thumbnails-path>
   </paths>
   <log-level>debug</log-level>
   <mixer>
      <blend-modes>true</blend-modes>
      <straight-alpha>true</straight-alpha>
      <chroma-key>true</chroma-key>
   </mixer>
   <thumbnails>
      <generate-thumbnails>false</generate-thumbnails>
   </thumbnails>
   <channels>
      <channel>
         <video-mode>PAL</video-mode>
         <straight-alpha-output>true</straight-alpha-output>
         <consumers>
            <screen>
               <device>2</device>
               <name>OUTOUT</name>
               <borderless>true</borderless>
            </screen>
         </consumers>
      </channel>
   </channels>
   <controllers>
      <tcp>
         <port>5250</port>
         <protocol>AMCP</protocol>
      </tcp>
   </controllers>
</configuration>
-----------------------------------------
[2017-09-07 17:58:24.862] [8460] [info]    Initialized html module.
[2017-09-07 17:58:24.862] [8460] [info]    Initializing OpenGL Device.
[2017-09-07 17:58:24.884] [8676] [info]    OpenGL 4.5.0 NVIDIA 358.91 NVIDIA Corporation
[2017-09-07 17:58:24.884] [8676] [info]    Successfully initialized OpenGL Device.
[2017-09-07 17:58:24.888] [8460] [info]    Initialized ffmpeg module.
[2017-09-07 17:58:24.889] [8460] [info]    Initialized bluefish module.
[2017-09-07 17:58:24.889] [8460] [info]    Initialized decklink module.
[2017-09-07 17:58:24.889] [8460] [info]    Initialized oal module.
[2017-09-07 17:58:24.889] [8460] [info]    Initialized newtek module.
[2017-09-07 17:58:24.889] [8460] [info]    Initialized ogl module.
[2017-09-07 17:58:24.889] [8460] [info]    Initialized flash module.
[2017-09-07 17:58:24.889] [8460] [info]    Initialized image module.
[2017-09-07 17:58:24.904] [8460] [info]    video_channel[1|PAL] Successfully Initialized.
[2017-09-07 17:58:24.909] [8460] [info]    
+---------------+
| filter_buffer |default--[720x576 64:45 bgra]--auto-inserted scaler 1:default
|   (buffer)    |
+---------------+

                                                             +-------------------+
auto-inserted scaler 0:default--[720x576 64:45 bgra]--default| filter_buffersink |
                                                             |   (buffersink)    |
                                                             +-------------------+

                                                             +-----------------+
auto-inserted scaler 1:default--[720x576 64:45 gbrp]--default| Parsed_format_0 |default--[720x576 64:45 gbrp]--Parsed_yadif_1:default
                                                             |    (format)     |
                                                             +-----------------+

                                                      +----------------+
Parsed_format_0:default--[720x576 64:45 gbrp]--default| Parsed_yadif_1 |default--[720x576 64:45 gbrp]--auto-inserted scaler 0:default
                                                      |    (yadif)     |
                                                      +----------------+

                                                     +------------------------+
Parsed_yadif_1:default--[720x576 64:45 gbrp]--default| auto-inserted scaler 0 |default--[720x576 64:45 bgra]--filter_buffersink:default
                                                     |        (scale)         |
                                                     +------------------------+

                                                    +------------------------+
filter_buffer:default--[720x576 64:45 bgra]--default| auto-inserted scaler 1 |default--[720x576 64:45 gbrp]--Parsed_format_0:default
                                                    |        (scale)         |
                                                    +------------------------+


[2017-09-07 17:58:24.910] [8460] [info]    OUTOUT [1|PAL] Successfully Initialized.
[2017-09-07 17:58:24.910] [8536] [info]    output[1] OUTOUT [1|PAL] Added.
[2017-09-07 17:58:24.911] [8460] [info]    Initialized channels.
[2017-09-07 17:58:24.911] [8460] [info]    WinSock2 Initialized.
[2017-09-07 17:58:24.911] [8460] [info]    Listener successfully initialized
[2017-09-07 17:58:24.911] [8460] [info]    Initialized controllers.
[2017-09-07 17:58:24.911] [8460] [info]    Initialized osc.
[2017-09-07 17:58:24.911] [8460] [info]    Started initial media information retrieval.
[2017-09-07 17:58:24.954] [5840] [info]    OUTOUT [1|PAL] Successfully Initialized.
[2017-09-07 17:58:24.970] [4248] [info]    flash-player[cg20.fth.pal|1024x576] Uninitialized.
[2017-09-07 17:58:24.972] [2760] [info]    flash[cg20.fth.pal|5000] Uninitialized.
[2017-09-07 17:58:25.260] [4252] [info]    Initial media information retrieval finished.
[2017-09-07 17:58:31.378] [5564] [info]    Accepted connection from 127.0.0.1 2
[2017-09-07 17:58:31.379] [5564] [info]    Received message from 127.0.0.1: CLEAR 1\r\n
[2017-09-07 17:58:31.379] [7396] [debug]   Executed command: ClearCommand
[2017-09-07 17:58:31.380] [7396] [info]    Sent message to 127.0.0.1: 202 CLEAR OK\r\n
[2017-09-07 17:58:31.436] [5564] [info]    Received message from 127.0.0.1: CG 1-1 ADD 1 LayerFlash1 1 <data><port>50679</port></data>\r\n
[2017-09-07 17:58:31.438] [7396] [info]    flash[cg20.fth.pal|0] Initialized.
[2017-09-07 17:58:31.438] [7396] [info]    flash[cg20.fth.pal|0] Invoking add-command: <invoke name="Add" returntype="xml"><arguments><number>1</number><string>LAYERFLASH1.ft</string><true/><string></string><string><![CDATA[ <data><port>50679</port></data>]]></string></arguments></invoke>
[2017-09-07 17:58:31.506] [4636] [debug]   flash-player[cg20.fth.pal|1024x576] [command]      <invoke name="OnCommand" returntype="xml"><arguments><string>Command recieved @GetInfo@?@</string></arguments></invoke>
[2017-09-07 17:58:31.533] [4636] [info]    flash-player[cg20.fth.pal|1024x576] Initialized.
[2017-09-07 17:58:31.534] [4636] [debug]   flash-player[cg20.fth.pal|1024x576] [command]      <invoke name="OnCommand" returntype="xml"><arguments><string>Command recieved @Add@1@</string></arguments></invoke>
[2017-09-07 17:58:31.598] [4636] [debug]   flash-player[cg20.fth.pal|1024x576] [activity]     <invoke name="OnActivity" returntype="xml"><arguments><string>Command finished @Add@1@</string></arguments></invoke>
[2017-09-07 17:58:31.623] [4636] [debug]   flash-player[cg20.fth.pal|1024x576] [activity]     <invoke name="OnActivity" returntype="xml"><arguments><string>Command finished @Play@1@</string></arguments></invoke>
[2017-09-07 17:58:31.716] [7396] [debug]   Executed command: CGCommand
[2017-09-07 17:58:31.716] [7396] [info]    Sent message to 127.0.0.1: 202 CG OK\r\n
[2017-09-07 17:58:31.716] [5564] [info]    Received message from 127.0.0.1: CG 1-3 ADD 1 LayerFlash2 1 <data><port>50679</port></data>\r\n
[2017-09-07 17:58:31.718] [7396] [info]    flash[cg20.fth.pal|0] Initialized.
[2017-09-07 17:58:31.718] [7396] [info]    flash[cg20.fth.pal|0] Invoking add-command: <invoke name="Add" returntype="xml"><arguments><number>1</number><string>LAYERFLASH2.ft</string><true/><string></string><string><![CDATA[ <data><port>50679</port></data>]]></string></arguments></invoke>
[2017-09-07 17:58:31.777] [8208] [debug]   flash-player[cg20.fth.pal|1024x576] [command]      <invoke name="OnCommand" returntype="xml"><arguments><string>Command recieved @GetInfo@?@</string></arguments></invoke>
[2017-09-07 17:58:31.790] [8208] [info]    flash-player[cg20.fth.pal|1024x576] Initialized.
[2017-09-07 17:58:31.793] [8208] [debug]   flash-player[cg20.fth.pal|1024x576] [command]      <invoke name="OnCommand" returntype="xml"><arguments><string>Command recieved @Add@1@</string></arguments></invoke>
[2017-09-07 17:58:31.842] [8208] [debug]   flash-player[cg20.fth.pal|1024x576] [activity]     <invoke name="OnActivity" returntype="xml"><arguments><string>Command finished @Add@1@</string></arguments></invoke>
[2017-09-07 17:58:31.921] [8208] [debug]   flash-player[cg20.fth.pal|1024x576] [activity]     <invoke name="OnActivity" returntype="xml"><arguments><string>Command finished @Play@1@</string></arguments></invoke>
[2017-09-07 17:58:31.922] [7396] [debug]   Executed command: CGCommand
[2017-09-07 17:58:31.922] [7396] [info]    Sent message to 127.0.0.1: 202 CG OK\r\n
[2017-09-07 17:58:31.922] [5564] [info]    Received message from 127.0.0.1: MIXER 1-2 FILL 0 0.2 0.2 0.2\r\n
[2017-09-07 17:58:31.922] [7396] [debug]   Executed command: MixerCommand
[2017-09-07 17:58:31.922] [7396] [info]    Sent message to 127.0.0.1: 202 MIXER OK\r\n
[2017-09-07 17:58:31.922] [5564] [info]    Received message from 127.0.0.1: PLAY 1-2 vid1.mp4\r\n
[2017-09-07 17:58:31.955] [7396] [info]    ffmpeg[vid1.mp4|1024x576i50.00|0/249] [video-decoder] H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
[2017-09-07 17:58:31.958] [7396] [debug]   [audio-decoder] AAC (Advanced Audio Coding) Selected channel layout STEREO
[2017-09-07 17:58:31.958] [7396] [info]    ffmpeg[vid1.mp4|1024x576i50.00|0/249] [audio-decoder] AAC (Advanced Audio Coding)
[2017-09-07 17:58:31.962] [7396] [info]    transition[empty=>ffmpeg[vid1.mp4|1024x576i50.00|0/249]] Initialized.
[2017-09-07 17:58:31.962] [7396] [debug]   Executed command: PlayCommand
[2017-09-07 17:58:31.963] [7396] [info]    Sent message to 127.0.0.1: 202 PLAY OK\r\n
[2017-09-07 17:58:31.991] [8800] [info]    transition[empty=>ffmpeg[vid1.mp4|1024x576i50.00|0/249]] End Of File.
[2017-09-07 17:58:32.009] [8800] [info]    
+---------------+
| filter_buffer |default--[1024x576 1:1 yuv420p]--filter_buffersink:default
|   (buffer)    |
+---------------+

                                                      +-------------------+
filter_buffer:default--[1024x576 1:1 yuv420p]--default| filter_buffersink |
                                                      |   (buffersink)    |
                                                      +-------------------+


[2017-09-07 17:58:32.009] [8800] [info]    [frame_muxer] simple 1024x576p25.00
[2017-09-07 17:58:32.017] [8800] [info]    transition[empty=>ffmpeg[vid1.mp4|1024x576p25.00|1/249]] Uninitialized.
I tested leaks memory, nope. :(

I did a test project, simpler than the current project, and the bug occurred after about an hour.

There is : https://github.com/Grouuu/casparBugTest

I don't really understand :(

Re: Flash Template Freeze

#2
I am chasing a similar problem for quite some time. I use it for sports and it is the clock, that frezzes after a while. The problem only occures on some machines and not on others. It seems to have to do with OpenGL or the GPU driver. I see the same as you, that the Flash template does respond, but the display gets frozzen. But I did not realize, that it's only the upper layer. Next thing I will try is to put the clock on a lower layer and anything else above it... But it would be good, if we could find out, what the problem is.
Didi Kunz
CasparCG Client-Programmer, Template Maker & Live CG-Operator
Media Support, CH-5722 Gränichen, Switzerland http://mediasupport.ch/
Problems? Guide to posting Bug reports & Feature requests

Re: Flash Template Freeze

#3
Did you observe this behavior with a single flash template?
All our projects with a single layer flash are not a problem, only the one that displays two (in different video layers).

I will have to look for another way to do in the meantime, thank you very much for your answer!

Re: Flash Template Freeze

#4
Dear Grouuu,

as I only had this problem on clients machines and not on mine, I created a test program, that you could run for me. There is a ZIP file here:
https://www.dropbox.com/s/ssjlveapyvudc ... t.zip?dl=0
It contains an .EXE, and a .DLL. These need to go into a folder somewhere. Then there is a .FT, that needs to go into the template folder and a .PNG that needs to go into the media folder. Before you run the exe, Caspar needs to be started. Then run test 1 and wait until something freezes. If the theory, that it's the uppermost layer, witch is freezing, is correct, the leftmost Timer should freeze first. Leave it running to see if there is any other timer also freezing. Test 2 adds a clear layer as topmost (the PNG) and probably after that no clock is freezing any more (hopefully).
Didi Kunz
CasparCG Client-Programmer, Template Maker & Live CG-Operator
Media Support, CH-5722 Gränichen, Switzerland http://mediasupport.ch/
Problems? Guide to posting Bug reports & Feature requests

Re: Flash Template Freeze

#8
In fact, I will have to change PC to test, the test is too "violent" for mine ...
From the beginning, the hours do not update regularly, and are shifting more and more. Hard to test under these conditions!
I'll watch this afternoon on a production PC.

Re: Flash Template Freeze

#9
Grouuu wrote:
08 Sep 2017, 11:44
In fact, I will have to change PC to test, the test is too "violent" for mine ...
From the beginning, the hours do not update regularly, and are shifting more and more. Hard to test under these conditions!
I'll watch this afternoon on a production PC.
Hahaha, yes, it's programmed far from optimal... Just as quick as possible. So I look forward to your findings it's running for more that 3 hours here, without a glitch.
Didi Kunz
CasparCG Client-Programmer, Template Maker & Live CG-Operator
Media Support, CH-5722 Gränichen, Switzerland http://mediasupport.ch/
Problems? Guide to posting Bug reports & Feature requests

Re: Flash Template Freeze

#10
So we were able to test it on another machine, that shows the problem. It seems not to be related on the position of the layer (beeing topmost, bottommost etc.) The problem appears randomly. It looks like it happens more often under Windows 10 than 7 and the older the GPU drivers are the less problems. We were not able to try it under CasparCG 2.1 yet.
Didi Kunz
CasparCG Client-Programmer, Template Maker & Live CG-Operator
Media Support, CH-5722 Gränichen, Switzerland http://mediasupport.ch/
Problems? Guide to posting Bug reports & Feature requests

Re: Flash Template Freeze

#16
Well, I have a problem on my side with the test you gave me (my server reboot without me finding why ...), but after more than 20 hours, test 1 was still working properly. It becomes too long for the test to be relevant.

On the other hand, I have set up on my project, on the upper layer, a transparent image (as in your test), and it did not prevent the template flash underneath freeze.
So I tried something else: instead of a transparent image, I put a transparent flash template.
The project has been running since yesterday, and for the moment it seems to work.

Re: Flash Template Freeze

#18
i have similar experience with flash templates
after a longer period (20+ days) flash stops working and current active template frezzes
templates can't be cleared or restarted without CCG server restart
using the recomended ax on win 7 with 2.0.7
Broadcast Live streaming | Video production
www.agatin.hr
cron