Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Unknow bug - Video wasn't upload #323

Open
vuisme opened this issue Dec 22, 2023 · 9 comments
Open

Unknow bug - Video wasn't upload #323

vuisme opened this issue Dec 22, 2023 · 9 comments
Labels
question Further information is requested

Comments

@vuisme
Copy link
Contributor

vuisme commented Dec 22, 2023

Sometime my bot can not upload video to Archive Group. I try to track and debug but nothing error show on exception. It's just gone and stuck at this screen and logs
image
image

I'm using celery mode. How to debug status after send video?
image
@BennyThink BennyThink added the question Further information is requested label Dec 22, 2023
@BennyThink
Copy link
Member

Is your bot busy with uploading? By default pyrogram will only upload one file at a time. You may need to adjust max_concurrent_transmissions, see here

9f9ff0a

@BennyThink BennyThink added the bug Something isn't working label Dec 22, 2023
@vuisme
Copy link
Contributor Author

vuisme commented Dec 22, 2023 •
edited

I have tried shutting down all Masters and Workers. Only tested with 1 single download link. This is full log

2023-12-22 09:20:51,179 INFO Set uid to user 0 succeeded
2023-12-22 09:20:51,181 INFO supervisord started with pid 1
2023-12-22 09:20:52,184 INFO spawned: 'worker' with pid 7
2023-12-22 09:20:52,187 INFO spawned: 'log' with pid 8
2023-12-22 09:20:52,190 INFO spawned: 'vnstat' with pid 9
2023-12-22 09:20:53,249 INFO success: log entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2023-12-22 09:20:53,249 INFO success: vnstat entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2023-12-22 09:20:57,254 INFO success: worker entered RUNNING state, process has stayed up for > than 5 seconds (startsecs)
[2023-12-22 09:21:01 base.py:454 I] Adding job tentatively -- it will be properly scheduled when the scheduler starts
[2023-12-22 09:21:01 base.py:895 I] Added job "auto_restart" to job store "default"
[2023-12-22 09:21:01 base.py:181 I] Scheduler started
/usr/local/lib/python3.11/site-packages/celery/platforms.py:829: SecurityWarning: You're running the worker with superuser privileges: this is
absolutely not recommended!

Please specify a different user using the --uid option.

User information: uid=0 euid=0 gid=0 egid=0

  warnings.warn(SecurityWarning(ROOT_DISCOURAGED.format(
Bootstrapping Celery worker now.....
 
 -------------- celery@euro-nudhmw v5.3.6 (emerald-rush)
--- ***** ----- 
-- ******* ---- Linux-5.15.0-1048-oracle-aarch64-with-glibc2.36 2023-12-22 09:21:04
- *** --- * --- 
- ** ---------- [config]
- ** ---------- .> app:         tasks:0xffffaf3e2290
- ** ---------- .> transport:   redis://sv1.vutn.net:6379/0
- ** ---------- .> results:     disabled://
- *** --- * --- .> concurrency: 10 (thread)
-- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)
--- ***** ----- 
 -------------- [queues]
                .> celery           exchange=celery(direct) key=celery
                

[tasks]
  . tasks.audio_task
  . tasks.direct_download_task
  . tasks.image_task
  . tasks.ytdl_download_task

[2023-12-22 09:21:04,256: WARNING/MainProcess] /usr/local/lib/python3.11/site-packages/celery/worker/consumer/consumer.py:507: CPendingDeprecationWarning: The broker_connection_retry configuration setting will no longer determine
whether broker connection retries are made during startup in Celery 6.0 and above.
If you wish to retain the existing behavior for retrying connections on startup,
you should set broker_connection_retry_on_startup to True.
  warnings.warn(

[2023-12-22 09:21:05,975: INFO/MainProcess] Connected to redis://sv1.vutn.net:6379/0
[2023-12-22 09:21:05,975: WARNING/MainProcess] /usr/local/lib/python3.11/site-packages/celery/worker/consumer/consumer.py:507: CPendingDeprecationWarning: The broker_connection_retry configuration setting will no longer determine
whether broker connection retries are made during startup in Celery 6.0 and above.
If you wish to retain the existing behavior for retrying connections on startup,
you should set broker_connection_retry_on_startup to True.
  warnings.warn(

[2023-12-22 09:21:06,834: INFO/MainProcess] mingle: searching for neighbors
[2023-12-22 09:21:10,410: INFO/MainProcess] mingle: all alone
[2023-12-22 09:21:15,398: INFO/MainProcess] celery@euro-nudhmw ready.
[2023-12-22 09:21:16,702: INFO/MainProcess] Events of group {task} enabled by remote.
[2023-12-22 09:22:18,107: INFO/MainProcess] Task tasks.ytdl_download_task[a9c5f832-c69f-4c0e-99fc-c9f6af9b427f] received
[2023-12-22 09:22:18,108: INFO/MainProcess] YouTube celery tasks started for https://www.tiktok.com/@karadenizli.maceraci/video/7310627800069803270?is_from_webapp=1&sender_device=pc
[2023-12-22 09:22:18,109: CRITICAL/MainProcess] BOT IS NOT STARTED YET: Client has not been started yet
[2023-12-22 09:22:18,351: INFO/MainProcess] Start creating a new auth key on DC2
[2023-12-22 09:22:18,352: INFO/MainProcess] Connecting...
[2023-12-22 09:22:18,370: INFO/MainProcess] Connected! Production DC2 - IPv4
[2023-12-22 09:22:19,406: INFO/MainProcess] Done auth key exchange: DhGenOk
[2023-12-22 09:22:19,407: INFO/MainProcess] Disconnected
[2023-12-22 09:22:19,416: INFO/MainProcess] Connecting...
[2023-12-22 09:22:19,434: INFO/MainProcess] Connected! Production DC2 - IPv4
[2023-12-22 09:22:19,435: INFO/MainProcess] NetworkTask started
[2023-12-22 09:22:19,610: INFO/MainProcess] Session initialized: Layer 158
[2023-12-22 09:22:19,610: INFO/MainProcess] Device: CPython 3.11.7 - Pyrogram 2.0.106
[2023-12-22 09:22:19,611: INFO/MainProcess] System: Linux 5.15.0-1048-oracle (en)
[2023-12-22 09:22:19,611: INFO/MainProcess] Session started
[2023-12-22 09:22:19,612: INFO/MainProcess] PingTask started
[2023-12-22 09:22:19,672: INFO/MainProcess] PingTask stopped
[2023-12-22 09:22:19,673: INFO/MainProcess] Disconnected
[2023-12-22 09:22:19,673: INFO/MainProcess] NetworkTask stopped
[2023-12-22 09:22:19,673: INFO/MainProcess] Session stopped
[2023-12-22 09:22:19,681: INFO/MainProcess] Start creating a new auth key on DC5
[2023-12-22 09:22:19,681: INFO/MainProcess] Connecting...
[2023-12-22 09:22:19,829: INFO/MainProcess] Connected! Production DC5 - IPv4
[2023-12-22 09:22:21,585: INFO/MainProcess] Done auth key exchange: DhGenOk
[2023-12-22 09:22:21,586: INFO/MainProcess] Disconnected
[2023-12-22 09:22:21,594: INFO/MainProcess] Connecting...
[2023-12-22 09:22:21,743: INFO/MainProcess] Connected! Production DC5 - IPv4
[2023-12-22 09:22:21,744: INFO/MainProcess] NetworkTask started
[2023-12-22 09:22:22,438: INFO/MainProcess] Session initialized: Layer 158
[2023-12-22 09:22:22,439: INFO/MainProcess] Device: CPython 3.11.7 - Pyrogram 2.0.106
[2023-12-22 09:22:22,439: INFO/MainProcess] System: Linux 5.15.0-1048-oracle (en)
[2023-12-22 09:22:22,439: INFO/MainProcess] Session started
[2023-12-22 09:22:22,439: INFO/MainProcess] PingTask started
[2023-12-22 09:22:22,995: INFO/MainProcess] Started 100 HandlerTasks
[2023-12-22 09:22:28,129: INFO/MainProcess] Downloading for https://www.tiktok.com/@karadenizli.maceraci/video/7310627800069803270?is_from_webapp=1&sender_device=pc with format bestvideo[ext=mp4][vcodec!*=av01][vcodec!*=vp09]+bestaudio[ext=m4a]/bestvideo+bestaudio
[2023-12-22 09:22:30,364: WARNING/MainProcess] ERROR: [TikTok] 7310627800069803270: Requested format is not available. Use --list-formats for a list of available formats
[2023-12-22 09:22:30,368: ERROR/MainProcess] Download failed for bestvideo[ext=mp4][vcodec!*=av01][vcodec!*=vp09]+bestaudio[ext=m4a]/bestvideo+bestaudio - https://www.tiktok.com/@karadenizli.maceraci/video/7310627800069803270?is_from_webapp=1&sender_device=pc, try another way
[2023-12-22 09:22:30,369: INFO/MainProcess] Downloading for https://www.tiktok.com/@karadenizli.maceraci/video/7310627800069803270?is_from_webapp=1&sender_device=pc with format bestvideo[vcodec^=avc]+bestaudio[acodec^=mp4a]/best[vcodec^=avc]/best
[2023-12-22 09:22:32,122: WARNING/MainProcess] 
[download]   0.0% of   25.97MiB at  Unknown B/s ETA Unknown
[2023-12-22 09:22:32,349: WARNING/MainProcess] 
[download]   0.0% of   25.97MiB at   13.18KiB/s ETA 33:38  
[2023-12-22 09:22:32,350: WARNING/MainProcess] 
[download]   0.0% of   25.97MiB at   30.60KiB/s ETA 14:29
[2023-12-22 09:22:32,351: WARNING/MainProcess] 
[download]   0.1% of   25.97MiB at   65.34KiB/s ETA 06:46
[2023-12-22 09:22:32,352: WARNING/MainProcess] 
[download]   0.1% of   25.97MiB at  134.44KiB/s ETA 03:17
[2023-12-22 09:22:32,353: WARNING/MainProcess] 
[download]   0.2% of   25.97MiB at  272.23KiB/s ETA 01:37
[2023-12-22 09:22:32,358: WARNING/MainProcess] 
[download]   0.5% of   25.97MiB at  536.18KiB/s ETA 00:49
[2023-12-22 09:22:32,369: WARNING/MainProcess] 
[download]   1.0% of   25.97MiB at    1.00MiB/s ETA 00:25
[2023-12-22 09:22:32,383: WARNING/MainProcess] 
[download]   1.9% of   25.97MiB at    1.90MiB/s ETA 00:13
[2023-12-22 09:22:32,400: WARNING/MainProcess] 
[download]   3.8% of   25.97MiB at    3.58MiB/s ETA 00:06
[2023-12-22 09:22:32,423: WARNING/MainProcess] 
[download]   7.7% of   25.97MiB at    6.64MiB/s ETA 00:03
[2023-12-22 09:22:32,453: WARNING/MainProcess] 
[download]  15.4% of   25.97MiB at   12.07MiB/s ETA 00:01
[2023-12-22 09:22:32,507: WARNING/MainProcess] 
[download]  30.8% of   25.97MiB at   20.77MiB/s ETA 00:00
[2023-12-22 09:22:32,535: WARNING/MainProcess] 
[download]  46.2% of   25.97MiB at   29.07MiB/s ETA 00:00
[2023-12-22 09:22:32,605: WARNING/MainProcess] 
[download]  61.6% of   25.97MiB at   33.20MiB/s ETA 00:00
[2023-12-22 09:22:32,635: WARNING/MainProcess] 
[download]  77.0% of   25.97MiB at   38.95MiB/s ETA 00:00
[2023-12-22 09:22:32,673: WARNING/MainProcess] 
[download]  92.4% of   25.97MiB at   43.48MiB/s ETA 00:00
[2023-12-22 09:22:32,690: WARNING/MainProcess] 
[download] 100.0% of   25.97MiB at   45.72MiB/s ETA 00:00
[2023-12-22 09:22:32,788: WARNING/MainProcess] 
[download] 100% of   25.97MiB in 00:00:00 at 36.19MiB/s  
[2023-12-22 09:22:32,789: WARNING/MainProcess] 
                                                       
[2023-12-22 09:22:32,808: INFO/MainProcess] Downloading for https://www.tiktok.com/@karadenizli.maceraci/video/7310627800069803270?is_from_webapp=1&sender_device=pc with format None
[2023-12-22 09:22:34,420: WARNING/MainProcess] 
[download] 100% of   25.97MiB
[2023-12-22 09:22:34,421: WARNING/MainProcess] 
                             
[2023-12-22 09:22:34,612: INFO/MainProcess] Download complete.
[2023-12-22 09:22:34,615: INFO/MainProcess] [PosixPath('/tmp/ytdl-nyuyffrc/İşveç Kütük Ocakta Doldurulmuş Dana Eti 🥩🏔❄️ #outdor #outdoorcooking #.mp4')]
[2023-12-22 09:22:35,152: INFO/MainProcess] Không có ảnh
ffmpeg version 5.1.4-0+deb12u1 Copyright (c) 2000-2023 the FFmpeg developers
  built with gcc 12 (Debian 12.2.0-14)
  configuration: --prefix=/usr --extra-version=0+deb12u1 --toolchain=hardened --libdir=/usr/lib/aarch64-linux-gnu --incdir=/usr/include/aarch64-linux-gnu --arch=arm64 --enable-gpl --disable-stripping --enable-gnutls --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libcodec2 --enable-libdav1d --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libglslang --enable-libgme --enable-libgsm --enable-libjack --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librabbitmq --enable-librist --enable-librubberband --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libsrt --enable-libssh --enable-libsvtav1 --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzimg --enable-libzmq --enable-libzvbi --enable-lv2 --enable-omx --enable-openal --enable-opencl --enable-opengl --enable-sdl2 --disable-sndio --enable-libjxl --enable-pocketsphinx --enable-librsvg --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-chromaprint --enable-frei0r --enable-libx264 --enable-libplacebo --enable-librav1e --enable-shared
  libavutil      57. 28.100 / 57. 28.100
  libavcodec     59. 37.100 / 59. 37.100
  libavformat    59. 27.100 / 59. 27.100
  libavdevice    59.  7.100 / 59.  7.100
  libavfilter     8. 44.100 /  8. 44.100
  libswscale      6.  7.100 /  6.  7.100
  libswresample   4.  7.100 /  4.  7.100
  libpostproc    56.  6.100 / 56.  6.100
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '/tmp/ytdl-nyuyffrc/İşveç Kütük Ocakta Doldurulmuş Dana Eti 🥩🏔❄️ #outdor #outdoorcooking #.mp4':
  Metadata:
    major_brand     : isom
    minor_version   : 512
    compatible_brands: isomiso2mp41
    aigc_info       : {"aigc_label_type": 0}
    comment         : vid:v09044g40000clq914nog65rg3ght4k0
    encoder         : Lavf58.76.100
  Duration: 00:01:29.95, start: 0.000000, bitrate: 2422 kb/s
  Stream #0:0[0x1](und): Audio: aac (HE-AACv2) (mp4a / 0x6134706D), 44100 Hz, stereo, fltp, 64 kb/s (default)
    Metadata:
      handler_name    : SoundHandler
      vendor_id       : [0][0][0][0]
  Stream #0:1[0x2](und): Video: hevc (Main) (hvc1 / 0x31637668), yuv420p(tv, bt709), 1080x1920, 2349 kb/s, SAR 1:1 DAR 9:16, 60 fps, 60 tbr, 15360 tbn (default)
    Metadata:
      handler_name    : VideoHandler
      vendor_id       : [0][0][0][0]
Stream mapping:
  Stream #0:1 (hevc) -> scale:default
  scale:default -> Stream #0:0 (png)
Press [q] to stop, [?] for help
[swscaler @ 0xaaaad1bc8020] No accelerated colorspace conversion found from yuv420p to rgb24.
[swscaler @ 0xaaaad2211c80] No accelerated colorspace conversion found from yuv420p to rgb24.
    Last message repeated 2 times
Output #0, image2, to '/tmp/ytdl-nyuyffrc/4ecb676ec9584b708283d74fb72f816c-thunmnail.png':
  Metadata:
    major_brand     : isom
    minor_version   : 512
    compatible_brands: isomiso2mp41
    aigc_info       : {"aigc_label_type": 0}
    comment         : vid:v09044g40000clq914nog65rg3ght4k0
    encoder         : Lavf59.27.100
  Stream #0:0: Video: png, rgb24(pc, gbr/bt709/bt709, progressive), 1080x1920 [SAR 1:1 DAR 9:16], q=2-31, 200 kb/s, 60 fps, 60 tbn
    Metadata:
      encoder         : Lavc59.37.100 png
[image2 @ 0xaaaad1aae470] The specified filename '/tmp/ytdl-nyuyffrc/4ecb676ec9584b708283d74fb72f816c-thunmnail.png' does not contain an image sequence pattern or a pattern is invalid.
[image2 @ 0xaaaad1aae470] Use a pattern such as %03d for an image sequence or use the -update option (with -frames:v 1 if needed) to write a single image.
frame=    1 fps=0.4 q=-0.0 size=N/A time=00:00:00.01 bitrate=N/A speed=0.00628x    
frame=    1 fps=0.3 q=-0.0 Lsize=N/A time=00:00:00.01 bitrate=N/A speed=0.00576x    
video:2302kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: unknown
[2023-12-22 09:22:44,730: WARNING/MainProcess] User 894875684 has no token, set download mode to Celery
[2023-12-22 09:22:45,414: INFO/MainProcess] Chat ID: botlogstbb
[2023-12-22 09:22:45,415: INFO/MainProcess] Cache ID: /tmp/ytdl-nyuyffrc/İşveç Kütük Ocakta Doldurulmuş Dana Eti 🥩🏔❄️ #outdor #outdoorcooking #.mp4
[2023-12-22 09:22:45,415: INFO/MainProcess] Group ID: botlogstbb
[2023-12-22 09:22:45,415: INFO/MainProcess] Sending as video
[2023-12-22 09:22:45,418: INFO/MainProcess] Connecting...
[2023-12-22 09:22:45,566: INFO/MainProcess] Connected! Production DC5 (media) - IPv4
[2023-12-22 09:22:45,567: INFO/MainProcess] NetworkTask started
[2023-12-22 09:22:46,240: INFO/MainProcess] Session initialized: Layer 158
[2023-12-22 09:22:46,240: INFO/MainProcess] Device: CPython 3.11.7 - Pyrogram 2.0.106
[2023-12-22 09:22:46,240: INFO/MainProcess] System: Linux 5.15.0-1048-oracle (en)
[2023-12-22 09:22:46,240: INFO/MainProcess] Session started
[2023-12-22 09:22:46,242: INFO/MainProcess] PingTask started

@BennyThink
Copy link
Member

From the log there's nothing strange. Can you try to adjust PYRO_WORKERS and max_concurrent_transmissions to appropriate value? Also try to pull the latest code, measure network activity by vnstat -l or similar tools

@vuisme
Copy link
Contributor Author

vuisme commented Dec 23, 2023 •
edited

From the log there's nothing strange. Can you try to adjust PYRO_WORKERS and max_concurrent_transmissions to appropriate value? Also try to pull the latest code, measure network activity by vnstat -l or similar tools

Hi Benny. I try remove 3 line:

                progress=upload_hook,
                progress_args=(bot_msg,),
                reply_markup=markup,

on send video and it's can upload again. Maybe have a bug from crash before when select reply message or something. I will follow and update soon

@BennyThink
Copy link
Member

Good to know. It may also because of upload_hook

@BennyThink BennyThink removed the bug Something isn't working label Dec 23, 2023
@vuisme vuisme closed this as completed Dec 24, 2023
@vuisme
Copy link
Contributor Author

vuisme commented Dec 27, 2023

I'm not sure if this is the cause. But it seems that if there is any error during the upload process, the redis.update_metrics("video_success") function will not be called, leading to the following tasks being affected including restarting the workers.
I tried putting redis.update_metrics("video_success") above the send commands and tracking more.

image

@vuisme vuisme reopened this Dec 27, 2023
@vuisme vuisme changed the title Unknow bug - Video was'nt upload to Archive Group Unknow bug - Video wasn't upload Dec 27, 2023
@BennyThink
Copy link
Member

Can you try to manually trigger an error when uploading files(like switch on/off your wifi)? I am not sure if update_metrics is the case but it could be an deadlock somewhere..

@vuisme
Copy link
Contributor Author

vuisme commented Dec 28, 2023

Can you try to manually trigger an error when uploading files(like switch on/off your wifi)? I am not sure if update_metrics is the case but it could be an deadlock somewhere..

I still get the error. really annoying. Common when restarting a worker to update a new image or using the /patch command. After that, all image and video upload tasks will not be able to be sent. Just gone. It can only be temporarily fixed by deleting 4 lines

                 progress=upload_hook,
                 progress_args=(bot_msg,),
                 reply_markup=markup,
                 **meta,

and reboot. And if I encounter the problem again later, I have to re-add these 4 lines and restart again LOL. it seems that changing the submitted function's arguments solves the task hanging problem

@BennyThink
Copy link
Member

then most likely it's caused by progress=upload_hook, progress_args=(bot_msg,), 🫠

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
question Further information is requested
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@BennyThink @vuisme