V2 mount issue

[Grumpy_Geoff]

V2 on 20210901, with microSD card inserted and powered USB drive attched.

I had a crash the other day, where it appears both the microSD card and USB drive were both mounted as /media/hdd (if that's possible).
The device information reported the same partition size for both, whereas the microSD card is 256GB and the USB drive is 1TB.

It appears to me that this then caused an issue for LogManager where one thread removed a file that the other wanted to do the same - "who moved my cheese?"

Silly me didn't check the "messages" log to see if anything of use was listed there.

Notice how the /media/hdd/logs directory is listed twice -

Code: Select all

{2192}< 43247.329> [LogManager] Trash Poll Started
{2286}< 43247.330> [LogManager] probing folders
{2286}< 43247.339> [LogManager] found following log's: ['/media/hdd/logs', '/media/hdd/logs', '/home/root/logs']
{2286}< 43247.339> [LogManager] looking in: /media/hdd/logs
{2286}< 43247.346> [LogManager] /media/hdd/logs/AutoVisit.210820_085659.log: Too old: AutoVisit.210820_085659.log 1629692973.08
{2286}< 43247.350> [eThread] old thread joined 0
{30118}< 43247.350> [setIoPrio] best-effort level 7 ok
{30118}< 43247.350> [eBackgroundFileEraser] deleting '/media/hdd/logs/AutoVisit.210820_085659.log.del'
{2286}< 43247.352> [LogManager] /media/hdd/logs/Enigma2-2021-08-20_08-53-59.log: Too old: Enigma2-2021-08-20_08-53-59.log 1629693791.09
{2286}< 43247.352> [LogManager] looking in: /media/hdd/logs
{30118}< 43247.354> [eBackgroundFileEraser] deleting '/media/hdd/logs/Enigma2-2021-08-20_08-53-59.log.del'
{2192}< 43247.358> [Task] >>> Error: [<Components.Task.FailedPostcondition instance at 0xacfa37b0>]
{2192}< 43247.358> [Task] job Components.Task.Job name=LogManager #tasks=1 completed with [<Components.Task.FailedPostcondition instance at 0xacfa37b0>] in Components.Task.Task name=Checking Logs...
{2192}< 43247.358> [Task] unrecoverable task failure
{2192}< 43247.358> LogManager
Error: [Failure instance: Traceback: <type 'exceptions.OSError'>: [Errno 2] No such file or directory: '/media/hdd/logs/Enigma2-2021-08-20_08-53-59.log.del'
/usr/lib/python2.7/threading.py:801:__bootstrap_inner
/usr/lib/python2.7/threading.py:754:run
/usr/lib/python2.7/site-packages/twisted/_threads/_threadworker.py:46:work
/usr/lib/python2.7/site-packages/twisted/_threads/_team.py:190:doWork
--- <exception caught here> ---
/usr/lib/python2.7/site-packages/twisted/python/threadpool.py:250:inContext
/usr/lib/python2.7/site-packages/twisted/python/threadpool.py:266:<lambda>
/usr/lib/python2.7/site-packages/twisted/python/context.py:122:callWithContext
/usr/lib/python2.7/site-packages/twisted/python/context.py:85:callWithContext
/usr/lib/enigma2/python/Screens/LogManager.py:129:JobTrash
/usr/lib/enigma2/python/Screens/LogManager.py:35:get_size
/usr/lib/python2.7/genericpath.py:57:getsize
]{2192}< 43247.358> 
{2192}< 43247.359> [Task] not retrying job.
{2192}< 43423.038> [NetworkTime] Updating
{2192}< 43423.038> [Console] command: /usr/bin/ntpdate-sync
{2192}< 43423.038> [eConsoleAppContainer] Starting /bin/sh
{2192}< 43429.783> [Console] finished: /usr/bin/ntpdate-sync
{2192}< 43429.784> [NetworkTime] setting E2 time: 1632354950.01
{2192}< 43451.784> [RecordTimer] Thu Sep 23 07:56:12 2021 activating state 1
{2192}< 43451.785> starting thread :writeable
{2192}< 43451.786> finished thread :writeable
{2192}< 43451.787> starting thread :freespace
{2192}< 43451.788> finished thread :freespace
{2192}< 43451.788> [RecordTimer] Thu Sep 23 07:56:12 2021 Found enough free space to record

Notice how the same set of trash directories are listed twice, one for each device -

Code: Select all

{2286}<  3992.868> [Trashcan] found following trashcan's: ['/media/hdd/.Trash', '/media/hdd/movie/.Trash', '/media/hdd/.Trash', '/media/hdd/movie/.Trash']

whereas the trashcans should report like this (different log file) -

Code: Select all

{8355}< 42168.070> [Trashcan] found following trashcan's: ['/media/hdd/.Trash', '/media/hdd/movie/.Trash', '/media/usb/.Trash', '/media/usb/movie/.Trash']

and the logs as -

Code: Select all

{2402}<   101.874> [LogManager] found following log's: ['/media/hdd/logs', '/home/root/logs']

Perhaps the microSD card was slower to mount than usual? Dead heat race condition between the microSD card and the powered USB drive?

[BigbobOz]

Interesting. I bought a microSD to timeshift to instead over the network to my T4 which for the most part works well but occasionally it stops working.

NFI why. To get it working again, I fumble around with initializing the card again, set Timeshift to the USB again, couple of restarts inbetween.

I'll see if I can find the logs you mention and post them.

Thanks,
Rob