Backblaze B2: transport hangs with "Deep recursion on subroutine"

cPanel & WHM Version
96

phil99

Active Member
Jun 10, 2018
34
10
8
UK
cPanel Access Level
Root Administrator
Since the upgrade to WHM 96, we are regularly seeing the following in the cpbackup_transporter logs:

Code:
[2021-05-19 02:27:53 +0100] info [cpbackup_transporter] Upload attempt #1 starting for /backup_cpanel/2021-05-19/accounts/account.tar.gz to backup_cpanel/2021-05-19/accounts/account.tar.gz for destination:  Backblaze B2
[2021-05-19 03:18:53 +0100] info [cpbackup_transporter] Deep recursion on subroutine "Cpanel::Transport::Files::Backblaze::_do_request" at /usr/local/cpanel/Cpanel/Transport/Files/Backblaze.pm line 297.
[2021-05-19 03:18:54 +0100] info [cpbackup_transporter] Deep recursion on subroutine "Cpanel::Transport::Files::Backblaze::_do_request" at /usr/local/cpanel/Cpanel/Transport/Files/Backblaze.pm line 269.
(The actual account name has been replaced with "account").

At this point, the transport process hangs.

So far, this has always occurred when transporting one particular account.


On a related note: when this occurs we stop the transporter process with:

Code:
/usr/local/cpanel/bin/cpbackup_transporter --stop
which reports:

Code:
Graceful shutdown of cPanel Backup Transporter Queue Daemon requested  -  complete
At this point, the remaining account.tar.gz files are still present in the backup directory, including the one on which the transport process hung. When we restart the cpbackup_transporter process, the transport process continues as expected and most of the remaining files are uploaded. However, no attempt is made to upload the file on which the transport process hung, and the file is silently deleted.

Should the transport process not realise that it had not successfully uploaded this file? Obviously, in this case at least, it might lead to a loop with the transport continually failing, but it might be appropriate in other circumstances?

Thanks.
 

cPRex

Jurassic Moderator
Staff member
Oct 19, 2014
6,148
784
313
cPanel Access Level
Root Administrator
Hey there! We've seen this error a few times in the past (I see 8 entries for it in the entire history of our ticket system) and each of those incidents ended with the user reaching out to Backblaze to resolve the issue. Was there also possible a 500 after shortly after the "Deep recursion on subroutine" lines?
 

phil99

Active Member
Jun 10, 2018
34
10
8
UK
cPanel Access Level
Root Administrator
Hi, no the next entry in the log is over 3 hours later when the process was shutdown:

Code:
[2021-05-19 06:33:23 +0100] info [cpbackup_transporter] Graceful shutdown due to SIGHUP
 

quanin

Well-Known Member
Aug 18, 2011
127
7
68
cPanel Access Level
Root Administrator
I own one of those 8 tickets in your history, @cPRex. I just disabled the B2 entry, because it only started doing it after an upgrade to 96 and Backblaze hadn't made any changes in the 24 hours previous. If CPanel ever gets around to fixing it, I'll reenable it.
 

cPRex

Jurassic Moderator
Staff member
Oct 19, 2014
6,148
784
313
cPanel Access Level
Root Administrator
The 8 tickets are spread out since 2017, so the issue doesn't seem to be related to a particular update. If you have a recent ticket in with us you can always reply or open a new one so we can do some additional testing, but I'm not seeing any specific issues that would relate to this issue on my end.
 

Blip Media

Member
Oct 16, 2020
5
2
3
UK
cPanel Access Level
Root Administrator
Just wanted to report that I'm seeing the exact same thing. Not on every backup, sometimes there will be several successful backups, but then a failed/partial backup with the same error reported in the transport log file - with the two same line numbers 297 & 296.

Backup process still active and backup files still on server drive ... which, over two backups is enough to use up most all of the available space on the server (which is how I became aware of it when customers reported the server as unresponsive).

I've been running backups to Backblaze like clockwork for years with literally zero problems until recently.

Would love to know if this is a cPanel issue and if so, what the fix is.

Thanks
 

Blip Media

Member
Oct 16, 2020
5
2
3
UK
cPanel Access Level
Root Administrator
Happened again last night:

Code:
[2021-06-13 06:15:32 +0100] info [cpbackup_transporter] cpbackup_transporter - Processing next task
[2021-06-13 06:15:32 +0100] info [cpbackup_transporter] Instantiating Object
[2021-06-13 06:15:32 +0100] info [cpbackup_transporter] Starting a "copy" operation on the "BBlaze" destination ID "*************************".
[2021-06-13 06:15:32 +0100] info [cpbackup_transporter] Base path for destination is backup
[2021-06-13 06:15:32 +0100] info [cpbackup_transporter] Validating destination path backup/2021-06-13/accounts/
[2021-06-13 06:15:34 +0100] info [cpbackup_transporter] Path exists
[2021-06-13 06:15:34 +0100] info [cpbackup_transporter] Uploading account backup /backup/2021-06-13/accounts/eee2222.tar.gz to backup/2021-06-13/accounts/eee2222.tar.gz (from 2021-06
-13/accounts/eee2222.tar.gz)
[2021-06-13 06:15:34 +0100] info [cpbackup_transporter] Attempting to upload /backup/2021-06-13/accounts/eee2222.tar.gz to backup/2021-06-13/accounts/eee2222.tar.gz for destination:
BBlaze
[2021-06-13 06:15:34 +0100] info [cpbackup_transporter] Upload attempt #1 starting for /backup/2021-06-13/accounts/eee2222.tar.gz to backup/2021-06-13/accounts/eee2222.tar.gz for des
tination:  BBlaze
[2021-06-13 07:09:43 +0100] info [cpbackup_transporter] Deep recursion on subroutine "Cpanel::Transport::Files::Backblaze::_do_request" at /usr/local/cpanel/Cpanel/Transport/Files/Ba
ckblaze.pm line 297.
[2021-06-13 07:09:43 +0100] info [cpbackup_transporter] Deep recursion on subroutine "Cpanel::Transport::Files::Backblaze::_do_request" at /usr/local/cpanel/Cpanel/Transport/Files/Ba
ckblaze.pm line 269.
 

High Voltage

Registered
Nov 8, 2013
3
1
53
cPanel Access Level
Root Administrator
Affecting me as well, 3 times now in the last couple of months.
Glad to know a fix is on the way. Yes my logs show a 500 error as the first sign anything has gone wrong.
 
  • Like
Reactions: cPRex

cPRex

Jurassic Moderator
Staff member
Oct 19, 2014
6,148
784
313
cPanel Access Level
Root Administrator
Some users are still reporting this happening in 96.0.11, and we have opened CPANEL-37482 for tracking of this issue. If you see this happening, please open a ticket with our team so we can investigate the issue directly on your machine.