Transcoder only wraps up when client is timed out?

Wowza Streaming Engine
1

Wowza Streaming Engine 4.0.4 from the AMI available here

Currently, I need to wait for the file to finish transcoding before I can use it again.

I’m looking at the logs and I see this:

INFO session comment 1420436222 client connectionClosed [1420436222] pingtimeout

INFO server comment - onStreamDestroy: 1

INFO server comment - TranscodingSession.shutdown[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d91412373547415]

INFO transcoder decoder-audio-stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d91412373547415 -

INFO transcoder encoder-audio-stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d91412373547415 {name: “aac”}

And then the transcoding is done. and the .tmp file is removed.

I’m assuming that “pingtimeout” is a natural event that happens due to inactivity. I don’t want to have the client sit there until it is naturally timed out before I can use the transcoded file.

Is there any way that I can force-close the connection either from the client or the server, without waiting for a “pingtimeout” so that I can use this transcoded file faster?

The client should be able to tell the server “I’m done”, and then the server should wrap up all the transcoding operations. Can I do this?

From the client, I’m already calling NetStream.close() and NetStream.dispose(), but that doesn’t seem to help

2

What can I do server-side to tell whether or not the file is finished transcoding?

3

Hi,

You have the ticket #105310 opened with our support team about this issue.

Please let us know if the suggested usage of NetConnection.close(); helped to stop the connection between your client and Wowza server.

Zoran

4

Great.

Thank you for the confirmation. I am also closing the support ticket.

Zoran

5

I tried implemented ILiveStreamTranscoderActionNotify and I put some logs inside onShutdownStart and onShtdownStop and I didn’t see them when “TranscodingSession.shutdown” was called, according to the startup.sh logs.

6

On the client I call NetStream.close()

Then I call my custom method, save()

And in that method, there’s this:

		
		Path path = Paths.get(dir+mp4Name+".tmp");
		
		while(Files.exists(path)){
			try { 
				Thread.sleep(1000);
			} catch (InterruptedException e) {
				// TODO Auto-generated catch block
				e.printStackTrace();
			}
			getLogger().info("Tmp file exists, waiting");
		}

So I make a 13 second video, hit stop, hit save, and then this happens:

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO session comment 57610946 client connectionClosed [57610946] pingtimeout

INFO session disconnect 57610946 -

INFO server comment - onDisconnect: 57610946

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO session comment 447864141 client connectionClosed [447864141] pingtimeout

INFO server comment - onStreamDestroy: 1

INFO server comment - TranscodingSession.shutdown[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d70001412632391723]

That’s 28 seconds until the transcoder deletes the .tmp file.

Is the transcoder being kept alive by the client? Does it preserve the tmp file because it thinks the client is still sending stuff? Or perhaps it just normally takes 28 seconds to live-transcode a 13 second file?

7

Here is a log from a successful attempt:

INFO server comment - LiveStreamPacketizerSanJose.endChunkTS[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395]: Add chunk: id:4 a/v/k:251/151/10 duration:10026

INFO server comment - TranscodingSession.close[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395]

INFO stream recordstop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395 -

INFO stream unpublish 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395 -

INFO server comment - onStreamDestroy: 1

INFO stream destroy 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395 -

INFO session disconnect 1958636839 -

INFO server comment - onDisconnect: 1958636839

INFO server comment - TranscodingSession.shutdown[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395]

INFO transcoder decoder-audio-stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395 -

INFO transcoder encoder-audio-stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395 {name: “aac”}

INFO stream unpublish 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395_aac -

INFO server comment - onStreamDestroy: 2

INFO stream destroy 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395_aac -

INFO session connect-pending 50.246.217.38 -

INFO server comment - onConnect: 553457279

INFO session connect 50.246.217.38 -

INFO server comment - onConnectAccept: 553457279

INFO server comment - onStreamCreate: 1

INFO stream create - -

INFO stream play 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395 -

INFO stream seek 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395 -

INFO server comment - Saving thumbnail

INFO server comment - AMFDataList:

[0] saveThumbnail

[1] 3.0

[2] null

[3] 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395

[4] {Array: size: 19053, data: [largeblock]}

INFO server comment - Thumbnail saved /usr/local/WowzaStreamingEngine/content/recorder/thumb_530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395.jpg

INFO stream stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395 -

INFO server comment - doSave hit

INFO server comment - AMFDataList:

[0] doSave

[1] 4.0

[2] null

[3] 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395

INFO server comment - Starting upload

INFO server comment - getting credentials

INFO server comment - attempting to upload 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395_aac.mp4 to xxxxxxxxxx

INFO server comment - mp4 upload complete xxxxxxxxxx 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395_aac.mp4

INFO server comment - getting credentials

INFO server comment - attempting to upload thumb_530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395.jpg to xxxxxxxxxx

INFO server comment - thumb upload complete xxxxxxxxxx thumb_530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395.jpg

INFO server comment - sending info to client rtmp://xxxxxxxxxx.cloudfront.net/cfx/st/530d8aa855df0c2d269a5a58/53a47a049c52c9d83a2d71d8/1412696439395_aac.mp4

INFO server comment - deleting 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412696439395

INFO server comment - deleting thumbnail

INFO server comment - deleting mp4 video

INFO server comment - deleting mp4 AAC video

The first line indicates a stream.

The second line is the transcoder closing which happens when I stop recording and publishing, then the transcoder shuts down. Now the transcoded file is ready to be used. Unless the transcoder shuts down, I cannot access the transcoded file.

All the lines after that is custom module stuff.

Here’s a log from an unsuccessful attempt:

INFO server comment - LiveStreamPacketizerSmoothStreaming.addFragment[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485]: Add chunk: type:video id:10 count:15 duration:1007

INFO server comment - TranscodingSession.close[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485]

INFO stream recordstop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 -

INFO stream unpublish 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 -

INFO session connect-pending 50.246.217.38 -

INFO server comment - onConnect: 968481495

INFO session connect 50.246.217.38 -

INFO server comment - onConnectAccept: 968481495

INFO server comment - onStreamCreate: 1

INFO stream create - -

INFO stream play 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 -

INFO stream seek 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 -

INFO server comment - Saving thumbnail

INFO server comment - AMFDataList:

[0] saveThumbnail

[1] 3.0

[2] null

[3] 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485

[4] {Array: size: 18915, data: [largeblock]}

INFO server comment - Thumbnail saved /usr/local/WowzaStreamingEngine/content/recorder/thumb_530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485.jpg

INFO server comment - LiveStreamPacketizerSmoothStreaming.addFragment[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485_aac]: Add chunk: type:video id:10 count:15 duration:1007

INFO stream stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 -

INFO server comment - doSave hit

INFO server comment - AMFDataList:

[0] doSave

[1] 4.0

[2] null

[3] 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485

INFO server comment - Starting upload

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - Tmp file exists, waiting

INFO server comment - LiveStreamPacketizerSmoothStreaming.addFragment[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485]: Add chunk: type:video id:10 count:15 duration:1007

INFO server comment - TranscodingSession.close[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485]

INFO stream recordstop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 -

INFO stream unpublish 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 -

INFO server comment - Tmp file exists, waiting

INFO session comment 404091380 client connectionClosed [404091380] pingtimeout

INFO server comment - onStreamDestroy: 1

INFO stream destroy 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 -

INFO server comment - TranscodingSession.shutdown[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485]

INFO transcoder decoder-audio-stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 -

INFO transcoder encoder-audio-stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485 {name: “aac”}

INFO session disconnect 404091380 -

INFO server comment - onDisconnect: 404091380

INFO stream unpublish 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485_aac -

INFO server comment - onStreamDestroy: 1

INFO stream destroy 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485_aac -

INFO server comment - Tmp file exists, waiting

INFO server comment - getting credentials

INFO server comment - attempting to upload 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485_aac.mp4 to xxxxxxxxxx

INFO server comment - mp4 upload complete xxxxxxxxxx 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485_aac.mp4

INFO server comment - getting credentials

INFO server comment - attempting to upload thumb_530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485.jpg to xxxxxxxxxx

INFO server comment - thumb upload complete xxxxxxxxxx thumb_530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485.jpg

INFO server comment - sending info to client rtmp://xxxxxxxxxx.cloudfront.net/cfx/st/530d8aa855df0c2d269a5a58/53a47a049c52c9d83a2d71d8/1412697135485_aac.mp4

INFO server comment - deleting 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412697135485

INFO server comment - deleting thumbnail

INFO server comment - deleting mp4 video

INFO server comment - deleting mp4 AAC video

For this one, you can see that the transcoding session closes twice, and then only when the client times out does the transcoding session shut down

8

I just attempted this with my custom modules disabled. The same thing happens: Here’s a copy/paste of the logs:

INFO server comment - LiveStreamPacketizerSmoothStreaming.addFragment[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117_aac]: Add chunk: type:audio id:0 count:32 duration:2053

INFO server comment - TranscodingSession.close[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117]

INFO stream recordstop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117 -

INFO stream unpublish 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117 -

INFO server comment - MediaCasterStreamValidator.init[player/definst]: Started

INFO server comment - ServerListenerEC2Variables#ApplicationInstanceNotify.onApplicationInstanceCreate[player/definst]: Auto-set application RTSP addresses: internal[bind]:10.213.146.195 external[origin,connection]:54.188.88.9

INFO application app-start definst player/definst

INFO session connect-pending 50.246.217.38 -

INFO session connect 50.246.217.38 -

INFO stream create - -

INFO stream play 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117 -

INFO stream seek 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117 -

WARN server comment - Missing function: saveThumbnail

INFO stream stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117 -

INFO session comment 1588047012 client connectionClosed [1588047012] pingtimeout

INFO server comment - TranscodingSession.shutdown[recorder/definst/530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117]

INFO transcoder decoder-audio-stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117 -

INFO transcoder encoder-audio-stop 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117 {name: “aac”}

INFO stream destroy 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117 -

INFO session disconnect 1588047012 -

INFO stream unpublish 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117_aac -

INFO stream destroy 530d8aa855df0c2d269a5a5853a47a049c52c9d83a2d71d81412700435117_aac -

You can see the pingtimeout before the transcoding session shuts down. There’s a ~28 second delay between the TranscodingSession.close events and the TranscodingSession.shutdown events.

9

This fixed this issue, and the transcoder is shut down immediately.