The officially official Devuan Forum!

You are not logged in.

#1 2021-06-21 16:31:42

Altoid
Member
Registered: 2017-05-07
Posts: 850  

[SOLVED] The perks of knowing

Hello:

Now that my exim4 is (apparently) working as expected, I can reap rewards of a sort.

I now get the news, both good and bad.

I have just received a notification related to the backintime utility that I had not ever seen before:

--- snip ---
Unhandled exception in thread started by <function __log_keyring_warning at 0x7fdf90288488>
Traceback (most recent call last):
  File "/usr/share/backintime/common/tools.py", line 1458, in __log_keyring_warning
TypeError: 'NoneType' object is not callable

Fortunately, in this case the notification is clear and I can go check what is going on.
I open the tools.py file to try and find the offending line which, according to jed has a different number (1457):

1456
1457 def __log_keyring_warning():
1458     from time import sleep
1459     sleep(0.1)
1460     logger.warning('import keyring failed')
1461
1462 if keyring is None and keyring_warn:
1463     #delay warning to give logger some time to import
1464     import _thread
1465     _thread.start_new_thread(__log_keyring_warning, ())
1466     # logger.warning('import keyring failed')
1467                                             # <-- this is the last line in the script

I wonder if this is happening now because of some update/upgrade?

In any case, python is just a family of long fat snakes to me.
ie: not a clue

The notification was sent by the Cron Daemon on date Mon, 21 Jun 2021 11:00:02 -0300.
The last backintime log entry was for a snapshot taken at Mon Jun 21 07:15:01 2021 local time and does not show any errors.

The crontab script is a system entry generated by the GUI and the python script comes with the application's installation.
Installed version is Python 2.7.16 (default, Oct 10 2019, 22:02:15).

Q: any idea as to why this has started happening now?

Thanks in advance,

A.

Last edited by Altoid (2021-06-22 02:16:02)

Offline

#2 2021-06-22 10:08:08

denk_mal
Member
Registered: 2017-12-01
Posts: 9  

Re: [SOLVED] The perks of knowing

This error looks very stange and maybe one of your installed python package is corrupted.

the line
'from time import sleep'
is a core python function to import an external package (in this case the time utils lib)

First of all you should test if the command from the crontab is working on a standard shell. The cron environment is sometimes very special.

If this is also not working  you could try the following:
start python2 on a shell and execute 'from time import sleep'
If this fails then the problem is in the python installation.
But it is working then it means that the backintime package has a problem.


Linux - be root
Windows systemd - reboot

Offline

#3 2021-06-22 10:52:39

Altoid
Member
Registered: 2017-05-07
Posts: 850  

Re: [SOLVED] The perks of knowing

Hello:

denk_mal wrote:

... looks very stange and maybe one of your installed python package is corrupted.

the line
'from time import sleep'
is a core python function to import an external package (in this case the time utils lib)

I see.

At first I thought that maybe the syntax could have been rendered wrong or broken by an update to python?
ie: similar to what happened with the last exim4 update.

But then my python installation is datestamped 10/2019 and this is the first time I have seen this error, so I don't think it is that.

denk_mal wrote:

... test if the command from the crontab is working on a standard shell. The cron environment is sometimes very special.

Right

groucho@devuan:~$ /usr/bin/nice -n 19 /usr/bin/ionice -c2 -n7 /usr/bin/backintime backup-job >/dev/null
groucho@devuan:~$ 
groucho@devuan:~$ mail
No mail for groucho
groucho@devuan:~$ 

The backintime application produced a backup and the log reported no errors.

========== Take snapshot (profile 1): Tue Jun 22 07:30:02 2021 ==========
denk_mal wrote:

... try the following:
start python2 on a shell and execute 'from time import sleep'

Here we go:

groucho@devuan:~$ python2
Python 2.7.16 (default, Oct 10 2019, 22:02:15) 
[GCC 8.3.0] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> from time import sleep
>>> exit ()
groucho@devuan:~$
denk_mal wrote:

If this fails ...

It seems that both tests were successful.

Maybe this is a perfect combination of unknowns?
ie: a glitch which did not disrupt anything and just produced an error message.

I will wait and see if it shows up again.
In the meantime I have filed an issue at the backintime github page -> https://github.com/bit-team/backintime/issues

Thank you very much for taking the time to write this up for me.

Best,

A.

Offline

#4 2021-06-22 11:36:06

denk_mal
Member
Registered: 2017-12-01
Posts: 9  

Re: [SOLVED] The perks of knowing

While backintime fails in your crontab but is working in a standard shell it has something to do with the environment that is used by python inside the crontab.


Linux - be root
Windows systemd - reboot

Offline

#5 2021-06-22 18:02:32

Altoid
Member
Registered: 2017-05-07
Posts: 850  

Re: [SOLVED] The perks of knowing

Hello:

denk_mal wrote:

... fails in your crontab but is working in a standard shell ...

That's the thing ...
It did not fail in crontab.

Altoid wrote:

The notification was sent by the Cron Daemon on date Mon, 21 Jun 2021 11:00:02 -0300.
The last backintime log entry was for a snapshot taken at Mon Jun 21 07:15:01 2021 local time and does not show any errors.

At least I can't make out a failure in /var/log/cron.log.

groucho@devuan:/var/log$ tail -600 cron.log
--- snip ---
Jun 21 07:04:47 devuan anacron[2132]: Anacron 2.3 started on 2021-06-21
Jun 21 07:04:47 devuan anacron[2132]: Will run job `cron.daily' in 5 min.
Jun 21 07:04:47 devuan anacron[2132]: Jobs will be executed sequentially
Jun 21 07:04:47 devuan cron[2200]: (CRON) INFO (pidfile fd = 3)
Jun 21 07:04:47 devuan cron[2201]: (CRON) STARTUP (fork ok)
Jun 21 07:04:47 devuan cron[2201]: (CRON) INFO (Running @reboot jobs)
Jun 21 07:05:01 devuan CRON[3030]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jun 21 07:09:47 devuan anacron[2132]: Job `cron.daily' started
Jun 21 07:09:47 devuan anacron[3660]: Updated timestamp for job `cron.daily' to 2021-06-21
Jun 21 07:10:42 devuan cracklib: no dictionary update necessary.
Jun 21 07:10:44 devuan anacron[2132]: Job `cron.daily' terminated
Jun 21 07:10:44 devuan anacron[2132]: Normal exit (1 job run)
Jun 21 07:15:01 devuan CRON[4019]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jun 21 07:15:01 devuan CRON[4020]: (groucho) CMD (/usr/bin/nice -n 19 /usr/bin/ionice -c2 -n7 /usr/bin/backintime backup-job >/dev/null)
Jun 21 07:17:01 devuan CRON[4142]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Jun 21 07:25:01 devuan CRON[4479]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jun 21 07:30:01 devuan CRON[4691]: (root) CMD ([ -x /etc/init.d/anacron ] && if [ ! -d /run/systemd/system ]; then /usr/sbin/invoke-rc.d anacron start >/dev/null; fi)
Jun 21 07:30:01 devuan CRON[4692]: (groucho) CMD (/usr/bin/nice -n 19 /usr/bin/ionice -c2 -n7 /usr/bin/backintime backup-job >/dev/null)
Jun 21 07:30:01 devuan anacron[4716]: Anacron 2.3 started on 2021-06-21
Jun 21 07:30:01 devuan anacron[4716]: Normal exit (0 jobs run)
Jun 21 07:35:01 devuan CRON[4986]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jun 21 07:45:01 devuan CRON[5386]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jun 21 07:45:01 devuan CRON[5387]: (groucho) CMD (/usr/bin/nice -n 19 /usr/bin/ionice -c2 -n7 /usr/bin/backintime backup-job >/dev/null)
Jun 21 07:55:01 devuan CRON[5783]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jun 21 08:00:01 devuan CRON[6000]: (root) CMD (timeshift --check --scripted)
Jun 21 08:00:01 devuan CRON[6001]: (groucho) CMD (/usr/bin/nice -n 19 /usr/bin/ionice -c2 -n7 /usr/bin/backintime backup-job >/dev/null)
Jun 21 08:00:02 devuan crontab[6047]: (root) LIST (root)
                                                          #
Jun 21 08:00:02 devuan crontab[6048]: (root) LIST (root)  # here is where the notification is sent ie: 11:00:02 -0300.
                                                          #
Jun 21 08:05:01 devuan CRON[6298]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jun 21 08:15:01 devuan CRON[6663]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jun 21 08:15:01 devuan CRON[6664]: (groucho) CMD (/usr/bin/nice -n 19 /usr/bin/ionice -c2 -n7 /usr/bin/backintime backup-job >/dev/null)
Jun 21 08:17:01 devuan CRON[6758]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Jun 21 08:25:01 devuan CRON[7052]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jun 21 08:30:01 devuan CRON[7230]: (root) CMD ([ -x /etc/init.d/anacron ] && if [ ! -d /run/systemd/system ]; then /usr/sbin/invoke-rc.d anacron start >/dev/null; fi)
Jun 21 08:30:01 devuan CRON[7231]: (groucho) CMD (/usr/bin/nice -n 19 /usr/bin/ionice -c2 -n7 /usr/bin/backintime backup-job >/dev/null)
Jun 21 08:30:01 devuan anacron[7255]: Anacron 2.3 started on 2021-06-21
Jun 21 08:30:01 devuan anacron[7255]: Normal exit (0 jobs run)
--- snip ---

Thanks for your input.

Best,

A.

Offline

#6 2021-06-23 08:01:08

denk_mal
Member
Registered: 2017-12-01
Posts: 9  

Re: [SOLVED] The perks of knowing

Hi

Sorry my mistake.

When I am talking about crontab then I am talking about the crontab file that sets up the environment.
But you are right; It is still the CRON command and logentry; The crontab log entries only occures when you execute the crontab commant
e.g. 'crontab -l' or 'crontab -e'

What I mean is if you execute the command from the crontab file in a statndard shell than there are a lot of environment settings already working
that came from /etc/profile, /etc/bash.bashrc, .profile, .bashrc or any other envirnment files that will be called on login or console opening.

cron on the other hand has by default NO environments setup so anything that is needed by a command has to be setup by the command itself.
(or in the crontab file but that's another story)

This is most of the time the reason why a command that works in a standard shell will fail in a cron call from the crontab file.


Linux - be root
Windows systemd - reboot

Offline

#7 2021-06-23 09:54:39

Altoid
Member
Registered: 2017-05-07
Posts: 850  

Re: [SOLVED] The perks of knowing

Hello:

denk_mal wrote:

Sorry ...

For? 8^)

denk_mal wrote:

... talking about crontab ...
... talking about the crontab file that sets up the environment.
... if you execute the command from the crontab file in a standard shell ...

And that's what I understood.
ie: one thing is executing the command listed in crontab from a shell and another is when cron actually executes that command.

denk_mal wrote:

... anything that is needed by a command has to be setup by the command itself.

Got it.
That command is set up by the application and I have not touched it.
Hence the warning:

#Back In Time system entry, this will be edited by the gui:
denk_mal wrote:

... reason why a command that works in a standard shell will fail in a cron call from the crontab file.

Yes, I've seen that some time ago.

In any case, up to now, cron.log has shown no issues with respect to the backintime script.
We'll see if I get some feedback from the GitHub site, it dos not seem to have much activity on behalf of the maintainers.
But it does not seem to be dead.

Thanks so much lot for your input.

Best,

A.

Offline

#8 2021-06-24 20:57:23

Altoid
Member
Registered: 2017-05-07
Posts: 850  

Re: [SOLVED] The perks of knowing

Hello:

Altoid wrote:

We'll see if I get some feedback from the GitHub site ...

UPDATE:

Looking around in the GitHub site I found a report from 10/2017, ie: four years ago.
It is (for all intent and purposes) identical to what I reported recently:

Unhandled exception in thread started by <function __log_keyring_warning at 0x7fd39670a400>
Traceback (most recent call last):
File "/usr/share/backintime/common/tools.py", line 1463, in __log_keyring_warning
TypeError: 'NoneType' object is not callable

The OP cites the same thing: happens very rarely. In my case, I had never seen it before.
He produced the output from --debug and that was it.

Unhandled exception in thread started by <function __log_keyring_warning at 0x7fd698dbf400>
Traceback (most recent call last):
File "/usr/share/backintime/common/tools.py", line 1463, in __log_keyring_warning
File "", line 2237, in _find_and_load
File "", line 2222, in _find_and_load_unlocked
File "", line 2150, in _find_spec
TypeError: 'NoneType' object is not callable

This was happening running backintime 1.1.20 under Linux 4.4.87-18.29-default x86_64. (Open Suse).
Here it is happening running backintime 1.1.24 under Linux 5.10.0-0.bpo.3-amd64 (Devuan Beowulf)

So ...

Best,

A.

Offline

#9 2021-06-24 21:49:35

golinux
Administrator
Registered: 2016-11-25
Posts: 2,247  

Re: [SOLVED] The perks of knowing

Please report the bug upstream.

Offline

#10 2021-06-24 22:43:44

Altoid
Member
Registered: 2017-05-07
Posts: 850  

Re: [SOLVED] The perks of knowing

Hello:

golinux wrote:

Please report the bug upstream.

Done.

Best,

A.

Offline

#11 2021-06-24 23:35:44

golinux
Administrator
Registered: 2016-11-25
Posts: 2,247  

Re: [SOLVED] The perks of knowing

Thanks.  You had to dig deep for that one . . .

Offline

#12 2021-06-25 00:23:00

Altoid
Member
Registered: 2017-05-07
Posts: 850  

Re: [SOLVED] The perks of knowing

Hello:

golinux wrote:

Thanks.

You're welcome.

golinux wrote:

You had to dig deep ...

It's nothing compared to what a great many people do every day for Linux.
Although I must admit that sometimes frustration does get the best of me and out! comes my otherwise hidden curmudgeonly personality. 8^D !!!

Best,

A.

Last edited by Altoid (2021-06-25 00:24:09)

Offline

Board footer