Search code examples
javascriptnode.jsffmpegchild-processstderr

node.js ffmpeg spawn child_process unexpected data output



I'm rather new to backend stuff, so please excuse, if my question is trivial.
For an Intranet project, I want to present a video element in a webpage (React, HLS.js Player).
The video sources are mpeg-ts streams delivered as udp multicast.
A small node.js / express server should handle the ffmpeg commands, to transcode the multicast to hls to display them in a browser.

Problem is the Output:
The output is emitted on stderr... even the process is working as expected.
Here is the respective code I wrote for transcoding so far:

const express = require("express");
const { spawn, exec } = require("child_process");
const process = require("process")

let ls;

const app = express();

app.get('/cam/:source', (body) => {
    const cam = body.params.source;
    console.log(cam);

    let source = "udp://239.1.1.1:4444";
    let stream = "/var/www/html/streams/tmp/cam1.m3u8"


    stream = spawn("ffmpeg", ["-re", "-i", source, "-c:v", "libx264", "-crf", "21", "-preset", "veryfast", "-c:a", "aac", "-b:a", "128k", "-ac", "2", "-f", "hls", "-hls_list_size", "5", "-hls_flags", "delete_segments", stream], {detached: true});

    stream.stdout.on("data", data => {
        console.log(`stdout: ${data}`);
    });

    stream.stderr.on("data", data => {
        console.log(`stderr: ${data}`);
    });

    stream.on("error", error => {
        console.log(`error: ${error.message}`);
    });

    stream.on("close", code => {
        console.log(`child process exited with code ${code}`);
    });
})

app.listen(5000, ()=> {
    console.log('Listening');
})

This is maybe only cosmetics, but it makes me wondering.
Here is the terminal output:

[nodemon] starting `node server.js`
Listening
camera stream reloaded
stderr: ffmpeg version 4.3.2-0+deb11u1ubuntu1 Copyright (c) 2000-2021 the FFmpeg developers
  built with gcc 10 (Ubuntu 10.2.1-20ubuntu1)

  --shortend--


pid:  4206
stderr: frame=    8 fps=0.0 q=0.0 size=N/A time=00:00:00.46 bitrate=N/A speed=0.931x    
pid:  4206
stderr: frame=   21 fps= 21 q=26.0 size=N/A time=00:00:00.96 bitrate=N/A speed=0.95x    
pid:  4206
stderr: frame=   33 fps= 22 q=26.0 size=N/A time=00:00:01.49 bitrate=N/A speed=0.982x    
pid:  4206
stderr: frame=   46 fps= 23 q=26.0 size=N/A time=00:00:02.00 bitrate=N/A speed=0.989x    
pid:  4206
stderr: frame=   58 fps= 23 q=26.0 size=N/A time=00:00:02.49 bitrate=N/A speed=0.986x    
pid:  4206

and so on...

Any helpful information would be highly appreciated!
Many thanks in advance


Solution

  • You don't need to worry about that output if it works as it should.

    Using spawn you've created a wrapper around a specific process, the output that comes through stream.stderr it's triggered by a warn/error of the inherited process, a warn is not something to be concerned off, especially if your app behaves correctly.

    I've put below a simple demo on how to trigger the warn & error so you can see more clearly what happens:

    index.js

    const {spawn} = require('child_process');
    
    const output = (label) => (data) => {
        let str = data.toString().split(/(\r\n|\n)+/).filter(i => i.trim().length);
        str.forEach(row => {
            console.log(`[${label}]`, row);
        })
    };
    let proc = spawn('node', ['proc.js'], {
        shell: true,
        env: {
            ...process.env
        },
    })
    
    proc.stdout.on('data', output('data'));
    proc.stderr.on('data', output('error'));
    

    proc.js

    setInterval(()=>{
        console.log('default log',new Date())
        console.info('info log', new Date())
        console.error('error log', new Date());
        console.warn('warn log', new Date());
    }, 1000);
    
    /** Output: 
    [data] default log 2021-09-05T10:03:22.283Z
    [error] error log 2021-09-05T10:03:22.287Z
    [error] warn log 2021-09-05T10:03:22.287Z
    [data] info log 2021-09-05T10:03:22.287Z
    [data] default log 2021-09-05T10:03:23.292Z
    [error] error log 2021-09-05T10:03:23.293Z
    [error] warn log 2021-09-05T10:03:23.293Z
    [data] info log 2021-09-05T10:03:23.293Z
    [data] default log 2021-09-05T10:03:24.299Z
    [error] error log 2021-09-05T10:03:24.299Z
    [error] warn log 2021-09-05T10:03:24.299Z
    [data] info log 2021-09-05T10:03:24.299Z
    

    I've ran ffmpeg -version, logs:

    [data] ffmpeg version git-2020-06-17-0b3bd00 Copyright (c) 2000-2020 the FFmpeg developers
    [data] built with gcc 9.3.1 (GCC) 20200523
    [data] configuration: --enable-gpl --enable-version3 --enable-sdl2 --enable-fontconfig --enable-gnutls --enable-iconv --enable-libass --enable-libdav1d --enable-libbluray --enable-libfreetype --enable-libmp3lame --enable-libopencore
    -amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-libopus --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libsrt --enable-libtheora --enable-libtwolame --enable-libvpx --enable-libwavpack --enable-libweb
    p --enable-libx264 --enable-libx265 --enable-libxml2 --enable-libzimg --enable-lzma --enable-zlib --enable-gmp --enable-libvidstab --enable-libvmaf --enable-libvorbis --enable-libvo-amrwbenc --enable-libmysofa --enable-libspeex --en
    able-libxvid --enable-libaom --disable-w32threads --enable-libmfx --enable-ffnvcodec --enable-cuda-llvm --enable-cuvid --enable-d3d11va --enable-nvenc --enable-nvdec --enable-dxva2 --enable-avisynth --enable-libopenmpt --enable-amf
    [data] libavutil      56. 55.100 / 56. 55.100
    [data] libavcodec     58. 92.100 / 58. 92.100
    [data] libavformat    58. 46.101 / 58. 46.101
    [data] libavdevice    58. 11.100 / 58. 11.100
    [data] libavfilter     7. 86.100 /  7. 86.100
    [data] libswscale      5.  8.100 /  5.  8.100
    [data] libswresample   3.  8.100 /  3.  8.100
    [data] libpostproc    55.  8.100 / 55.  8.100
    

    I've also ran a ffmpeg process for a conversion and the file was ok, here are the logs:

    [error] ffmpeg version git-2020-06-17-0b3bd00 Copyright (c) 2000-2020 the FFmpeg developers
    [error]   built with gcc 9.3.1 (GCC) 20200523
    [error]   configuration: --enable-gpl --enable-version3 --enable-sdl2 --enable-fontconfig --enable-gnutls --enable-iconv --enable-libass --enable-libdav1d --enable-libbluray --enable-libfreetype --enable-libmp3lame --enable-libopenc
    ore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-libopus --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libsrt --enable-libtheora --enable-libtwolame --enable-libvpx --enable-libwavpack --enable-lib
    webp --enable-libx264 --enable-libx265 --enable-libxml2 --enable-libzimg --enable-lzma --enable-zlib --enable-gmp --enable-libvidstab --enable-libvmaf --enable-libvorbis --enable-libvo-amrwbenc --enable-libmysofa --enable-libspeex -
    -enable-libxvid --enable-libaom --disable-w32threads --enable-libmfx --enable-ffnvcodec --enable-cuda-llvm --enable-cuvid --enable-d3d11va --enable-nvenc --enable-nvdec --enable-dxva2 --enable-avisynth --enable-libopenmpt --enable-a
    mf
    [error]   libavutil      56. 55.100 / 56. 55.100
    [error]   libavcodec     58. 92.100 / 58. 92.100
    [error]   libavformat    58. 46.101 / 58. 46.101
    [error]   libavdevice    58. 11.100 / 58. 11.100
    [error]   libavfilter     7. 86.100 /  7. 86.100
    [error]   libswscale      5.  8.100 /  5.  8.100
    [error]   libswresample   3.  8.100 /  3.  8.100
    [error]   libpostproc    55.  8.100 / 55.  8.100
    [error] Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '2020-11-23_18-47-52.mp4':
    [error]   Metadata:
    [error]     major_brand     : isom
    [error]     minor_version   : 512
    [error]     compatible_brands: isomiso2avc1mp41
    [error]     encoder         : Lavf58.29.100
    [error]   Duration: 00:00:03.17, start: 0.000000, bitrate: 30039 kb/s
    [error]     Stream #0:0(und)
    [error] : Video: h264 (High) (avc1 / 0x31637661), yuvj420p(pc, bt709), 1920x1080 [SAR 1:1 DAR 16:9], 30026 kb/s, 60 fps, 60 tbr, 15360 tbn, 120 tbc (default)
    [error]     Metadata:
    [error]       handler_name    : VideoHandler
    [error]     Stream #0:1(und): Audio: aac (LC) (mp4a / 0x6134706D), 44100 Hz, stereo, fltp, 2 kb/s (default)
    [error]     Metadata:
    [error]       handler_name    : SoundHandler
    [error] Stream mapping:
    [error]   Stream #0:0 -> #0:0 (h264 (native) -> hevc (libx265))
    [error]   Stream #0:1 -> #0:1 (aac (native) -> aac (native))
    [error] Press [q] to stop, [?] for help
    [error] [swscaler @ 000002cddcf89d40] deprecated pixel format used, make sure you did set range correctly
    [error] x265 [info]: HEVC encoder version 3.3+29-1e3dbf09ee4f
    [error] x265 [info]: build info [Windows][GCC 9.3.1][64 bit] 8bit+10bit
    [error] x265 [info]: using cpu capabilities: MMX2 SSE2Fast LZCNT SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2
    [error] x265 [info]: Main profile, Level-4.1 (Main tier)
    [error] x265 [info]: Thread pool created using 12 threads
    [error] x265 [info]: Slices                              : 1
    [error] x265 [info]: frame threads / pool features       : 3 / wpp(30 rows)
    [error] x265 [warning]: VBV maxrate unspecified, assuming CBR
    [error] x265 [info]: Coding QT: max CU size, min CU size : 64 / 8
    [error] x265 [info]: Residual QT: max TU size, max depth : 32 / 1 inter / 1 intra
    [error] x265 [info]: ME / range / subpel / merge         : hex / 57 / 1 / 2
    [error] x265 [info]: Keyframe min / max / scenecut / bias  : 25 / 250 / 40 / 5.00
    [error] x265 [info]: Lookahead / bframes / badapt        : 15 / 4 / 0
    [error] x265 [info]: b-pyramid / weightp / weightb       : 1 / 1 / 0
    [error] x265 [info]: References / ref-limit  cu / depth  : 2 / on / on
    [error] x265 [info]: AQ: mode / str / qg-size / cu-tree  : 2 / 1.0 / 32 / 1
    [error] x265 [info]: Rate Control / qCompress            : ABR-800 kbps / 0.60
    [error] x265 [info]: VBV/HRD buffer / max-rate / init    : 1200 / 800 / 0.750
    [error] x265 [info]: tools: rd=2 psy-rd=2.00 early-skip rskip mode=1 signhide tmvp
    [error] x265 [info]: tools: fast-intra strong-intra-smoothing lslices=8 deblock sao
    [error] Output #0, mp4, to 'outputXZ.mp4':
    [error]   Metadata:
    [error]     major_brand     : isom
    [error]     minor_version   : 512
    [error]     compatible_brands: isomiso2avc1mp41
    [error]     encoder         : Lavf58.46.101
    [error]     Stream #0:0(und): Video: hevc (libx265) (hvc1 / 0x31637668), yuv420p, 1080x1920 [SAR 256:81 DAR 16:9], q=-1--1, 800 kb/s, 60 fps, 15360 tbn, 60 tbc (default)
    [error]     Metadata:
    [error]       handler_name    : VideoHandler
    [error]       encoder         : Lavc58.92.100 libx265
    [error]     Side data:
    [error]       cpb: bitrate max/min/avg: 0/0/800000 buffer size: 1200000 vbv_delay: N/A
    [error]     Stream #0:1(und): Audio: aac (LC) (mp4a / 0x6134706D), 44100 Hz, stereo, fltp, 128 kb/s (default)
    [error]     Metadata:
    [error]       handler_name    : SoundHandler
    [error]       encoder         : Lavc58.92.100 aac
    [error] frame=   47 fps=0.0 q=39.0 size=       0kB time=00:00:00.95 bitrate=   0.4kbits/s speed=1.89x
    [error] frame=  110 fps=109 q=11.0 size=       0kB time=00:00:01.97 bitrate=   0.2kbits/s speed=1.96x
    [error] frame=  172 fps=114 q=5.0 size=       0kB time=00:00:03.04 bitrate=   0.1kbits/s speed=2.01x
    [error] frame=  190 fps=106 q=6.0 Lsize=      36kB time=00:00:03.15 bitrate=  94.2kbits/s speed=1.76x
    [error] video:27kB audio:1kB subtitle:0kB other streams:0kB global headers:2kB muxing overhead: 31.662476%
    [error] x265 [info]: frame I:      1, Avg QP:50.77  kb/s: 296.16
    [error] x265 [info]: frame P:     38, Avg QP:22.16  kb/s: 67.17
    [error] x265 [info]: frame B:    151, Avg QP:17.18  kb/s: 65.79
    [error] x265 [info]: Weighted P-Frames: Y:0.0% UV:0.0%
    [error] x265 [info]: consecutive B-frames: 2.6% 0.0% 0.0% 2.6% 94.9%
    [error] encoded 190 frames in 1.75s (108.45 fps), 67.28 kb/s, Avg QP:18.35
    [error] [aac @ 000002cddd6d0a80] Qavg: 65536.000
    

    Unfortunately you don't have control over the process to change the output, you just need to use it as it is. Just don't put all your faith in the app output, it's there so you can see if things go ok or not.

    However, you have control over the output you catch, which you can modify how you see fit, as i did in the output function.

    PS: Any processes that exits with an exitCode different than 0 are considered as failed. Sometimes the programmer can force a process.exit(1) on a process that behaved correctly without knowing this, and of course if someone else it's using that process, their error events/conditions will trigger.