selenoid icon indicating copy to clipboard operation
selenoid copied to clipboard

Published 20 hours ago • verified publisher icon aerokube

Session videos and logs do not exist

Open adamopanast opened this issue 8 months ago • 4 comments

Hello, I am using selenoid and behave framework to run some selenium automated test andi I face some issues with session videos and session logs. First things first, I run selenoid as a container using the following command :

/usr/bin/docker run --name selenoid --rm -p 4444:4444 
    -v /home/selenoid/.aerokube/selenoid:/etc/selenoid 
    -v /var/run/docker.sock:/var/run/docker.sock 
    -v /home/selenoid/bucket/videos/:/opt/selenoid/video 
    -v /home/selenoid/bucket/logs/:/opt/selenoid/logs 
    -e OVERRIDE_VIDEO_OUTPUT_DIR=/home/selenoid/bucket/videos/ 
    aerokube/selenoid:latest-release 
    -conf /etc/selenoid/browsers.json 
    -video-output-dir /opt/selenoid/video 
    -log-output-dir /opt/selenoid/logs

I also use selenoid UI and everything seems to work as expected. The request contains the following capabilities configuration :

            "browserName": "chrome",
            "version": "",
            "platform": "",
            "selenoid:options": {
                "enableVNC": True,
                "enableLogs": True,
                "enableVideo": True 
            }
        }

So, vnc streaming works as expected, selenium tests are successfully executed, when a job is triggered selenoid spins up a browser container and a video recorder container. I've got the following docker-logs on video container :

ffmpeg version 4.3 Copyright (c) 2000-2020 the FFmpeg developers
  built with gcc 9.3.0 (Alpine 9.3.0)
  configuration: --prefix=/usr --enable-avfilter --enable-gpl --enable-libx264 --enable-libpulse --enable-static --enable-small --disable-ffplay --disable-ffprobe --disable-doc --disable-htmlpages --disable-manpages --disable-podpages --disable-txtpages --disable-w32threads --disable-alsa --disable-audiotoolbox --disable-cuda --disable-cuvid --disable-d3d11va --disable-dxva2 --disable-nvenc --disable-vaapi --disable-vdpau --disable-videotoolbox --disable-librtmp --disable-devices --enable-indev=xcbgrab --enable-indev=pulse --disable-debug
  libavutil      56. 51.100 / 56. 51.100
  libavcodec     58. 91.100 / 58. 91.100
  libavformat    58. 45.100 / 58. 45.100
  libavdevice    58. 10.100 / 58. 10.100
  libavfilter     7. 85.100 /  7. 85.100
  libswscale      5.  7.100 /  5.  7.100
  libswresample   3.  7.100 /  3.  7.100
  libpostproc    55.  7.100 / 55.  7.100
Guessed Channel Layout for Input Stream #0.0 : stereo
Input #0, pulse, from 'default':
  Duration: N/A, start: 1716978393.161954, bitrate: 1536 kb/s
    Stream #0:0: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s
[x11grab @ 0x7fb73fe78080] Cannot get the image data event_error: response_type:0 error_code:1 sequence:9 resource_id:1293 minor_code:4 major_code:130.
[x11grab @ 0x7fb73fe78080] Continuing without shared memory.
[x11grab @ 0x7fb73fe78080] Stream #0: not enough frames to estimate rate; consider increasing probesize
Input #1, x11grab, from 'browser:99':
  Duration: N/A, start: 1716978393.255765, bitrate: 796262 kb/s
    Stream #1:0: Video: rawvideo (BGR[0] / 0x524742), bgr0, 1920x1080, 796262 kb/s, 12 fps, 1000k tbr, 1000k tbn, 1000k tbc
Stream mapping:
  Stream #1:0 -> #0:0 (rawvideo (native) -> h264 (libx264))
  Stream #0:0 -> #0:1 (pcm_s16le (native) -> aac (native))
Press [q] to stop, [?] for help
[libx264 @ 0x7fb74031b300] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2 AVX512
[libx264 @ 0x7fb74031b300] profile High, level 4.0, 4:2:0, 8-bit
[libx264 @ 0x7fb74031b300] 264 - core 157 - H.264/MPEG-4 AVC codec - Copyleft 2003-2018 - http://www.videolan.org/x264.html - options: cabac=1 ref=3 deblock=1:0:0 analyse=0x3:0x113 me=hex subme=7 psy=1 psy_rd=1.00:0.00 mixed_ref=1 me_range=16 chroma_me=1 trellis=1 8x8dct=1 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=-2 threads=3 lookahead_threads=1 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=3 b_pyramid=2 b_adapt=1 b_bias=0 direct=1 weightb=1 open_gop=0 weightp=2 keyint=250 keyint_min=12 scenecut=40 intra_refresh=0 rc_lookahead=40 rc=crf mbtree=1 crf=23.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 ip_ratio=1.40 aq=1:1.00
Output #0, mp4, to '/data/selenoidd84c9f06de0ce2a782c0270490ec1eab.mp4':
  Metadata:
    encoder         : Lavf58.45.100
    Stream #0:0: Video: h264 (libx264) (avc1 / 0x31637661), yuv420p(progressive), 1920x1080, q=-1--1, 12 fps, 12288 tbn, 12 tbc
    Metadata:
      encoder         : Lavc58.91.100 libx264
    Side data:
      cpb: bitrate max/min/avg: 0/0/0 buffer size: 0 vbv_delay: N/A
    Stream #0:1: Audio: aac (mp4a / 0x6134706D), 48000 Hz, stereo, fltp, 128 kb/s
    Metadata:
      encoder         : Lavc58.91.100 aac
[pulse @ 0x7fb73ffbd3c0] Thread message queue blocking; consider raising the thread_queue_size option (current value: 8)
[aac @ 0x7fb73fe5b500] Queue input is backward in time04.75 bitrate=   0.1kbits/s speed=0.55x     
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230123, current: 202113; changing to 230124. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230124, current: 203137; changing to 230125. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230125, current: 204161; changing to 230126. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230126, current: 205185; changing to 230127. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230127, current: 206209; changing to 230128. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230128, current: 207233; changing to 230129. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230129, current: 208257; changing to 230130. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230130, current: 209281; changing to 230131. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230131, current: 210305; changing to 230132. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230132, current: 211329; changing to 230133. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230133, current: 212353; changing to 230134. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230134, current: 213377; changing to 230135. This may result in incorrect timestamps in the output file.
[aac @ 0x7fb73fe5b500] Queue input is backward in time
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230135, current: 214401; changing to 230136. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230136, current: 215425; changing to 230137. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230137, current: 183662; changing to 230138. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230138, current: 184686; changing to 230139. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230139, current: 185710; changing to 230140. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230140, current: 186734; changing to 230141. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230141, current: 187758; changing to 230142. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230142, current: 188782; changing to 230143. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230143, current: 189806; changing to 230144. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230144, current: 190830; changing to 230145. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230145, current: 191854; changing to 230146. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230146, current: 192878; changing to 230147. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230147, current: 193902; changing to 230148. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230148, current: 194926; changing to 230149. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230149, current: 195950; changing to 230150. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230150, current: 196974; changing to 230151. This may result in incorrect timestamps in the output file.
[aac @ 0x7fb73fe5b500] Queue input is backward in time
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230151, current: 197998; changing to 230152. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230152, current: 199022; changing to 230153. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230153, current: 193703; changing to 230154. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7fb73feea700] Non-monotonous DTS in output stream 0:1; previous: 230154, current: 194727; changing to 230155. This may result in incorrect timestamps in the output file.

and the following logs on selenoid container :

2024/05/30 07:47:35 [20531] [SERVICE_STARTED] [selenoid/chrome:122.0] [3eb6d8a41832e302f1dd4159ef0f4435d963fb89cfb0d7828129e97094c4668e] [0.05s]
2024/05/30 07:47:35 [20531] [PROXY_TO] [3eb6d8a41832e302f1dd4159ef0f4435d963fb89cfb0d7828129e97094c4668e] [http://172.17.0.5:4444/]
2024/05/30 07:47:35 [20531] [SESSION_ATTEMPTED] [http://172.17.0.5:4444/] [1]
2024/05/30 07:47:36 [20531] [SESSION_CREATED] [2b3d9e7be06814579bb059fdc81fe041] [1] [1.54s]
2024/05/30 07:47:58 [20555] [CLIENT_DISCONNECTED] [unknown] [15.160.108.24, 10.68.48.208] [Error: context canceled]
2024/05/30 07:48:58 [20555] [SESSION_TIMED_OUT] [2b3d9e7be06814579bb059fdc81fe041]
2024/05/30 07:48:58 [20568] [SESSION_DELETED] [2b3d9e7be06814579bb059fdc81fe041]
2024/05/30 07:48:58 [20531] [STOPPING_VIDEO_CONTAINER] [4ec7c1a80dac63a298468ea8eca454b56f8d74e04ec4af42ce9692f8d81c566a]
2024/05/30 07:48:59 [20531] [REMOVING_CONTAINER] [4ec7c1a80dac63a298468ea8eca454b56f8d74e04ec4af42ce9692f8d81c566a]
2024/05/30 07:48:59 [20531] [FAILED_TO_REMOVE_CONTAINER] [4ec7c1a80dac63a298468ea8eca454b56f8d74e04ec4af42ce9692f8d81c566a] [Error response from daemon: removal of container 4ec7c1a80dac63a298468ea8eca454b56f8d74e04ec4af42ce9692f8d81c566a is already in progress]
2024/05/30 07:48:59 [20531] [REMOVING_CONTAINER] [3eb6d8a41832e302f1dd4159ef0f4435d963fb89cfb0d7828129e97094c4668e]
2024/05/30 07:48:59 [20531] [CONTAINER_REMOVED] [3eb6d8a41832e302f1dd4159ef0f4435d963fb89cfb0d7828129e97094c4668e]
2024/05/30 07:48:59 [20531] [VIDEO_ERROR] [Failed to rename /opt/selenoid/video/selenoid92dbde4eb6039b4452bf0a91af556d09.mp4 to /opt/selenoid/video/2b3d9e7be06814579bb059fdc81fe041.mp4: rename /opt/selenoid/video/selenoid92dbde4eb6039b4452bf0a91af556d09.mp4 /opt/selenoid/video/2b3d9e7be06814579bb059fdc81fe041.mp4: no such file or directory]

File /opt/selenoid/video/selenoid92dbde4eb6039b4452bf0a91af556d09.mp4 really does not exist , so its obvious that impossible to rename it. But why does not exist ?

In random times I get also the following error on selenoid container :

2024/05/30 09:18:41 [21623] [VIDEO_ERROR] [Failed to list directory /opt/selenoid/logs: readdirent /opt/selenoid/video: invalid argument]
2024/05/30 09:26:06 [21712] [VIDEO_ERROR] [Failed to list directory /opt/selenoid/logs: readdirent /opt/selenoid/video: invalid argument]
2024/05/30 09:37:26 [21848] [VIDEO_ERROR] [Failed to list directory /opt/selenoid/logs: readdirent /opt/selenoid/video: invalid argument]
2024/05/30 09:41:51 [21901] [VIDEO_ERROR] [Failed to list directory /opt/selenoid/logs: readdirent /opt/selenoid/video: invalid argument]
2024/05/30 09:42:36 [21910] [VIDEO_ERROR] [Failed to list directory /opt/selenoid/logs: readdirent /opt/selenoid/video: invalid argument]
2024/05/30 09:46:21 [21955] [VIDEO_ERROR] [Failed to list directory /opt/selenoid/logs: readdirent /opt/selenoid/video: invalid argument]

If I touch a file on conainers /opt/selenoid/logs I cont list it or retrieve it on http://localhost:4444/logs/

  • I can confirm that if I touch a test file on video path inside container ( $touch /opt/selenoid/video/test123.txt ) a "video player" appears on UI for the new file ( that behaves as a 0 time video ).
  • Container starts from user selenoid who is also the owner of the local folder /home/selenoid/bucket/videos/ .
  • I can confirm that if I touch a file on containers /opt/selenoid/video I can list it on local videos folder.

Accordin to official documentation the configuration of my selenoid instance seems to be ok. Is there anything else that could case these issues ?

Thanks !

adamopanast avatar May 30 '24 10:05 adamopanast