× К оглавлению На главную Об авторе

   Дата и время публикации:

Проблемы и решение

1. Суть проблемы

После того, как была смонтирована директория poky-building по NFS на гостевой ВМ сборочной машины Yocto/poky была выявлена проблема, связанная с ошибкой выполнения функции do_clean при повторном вызове одной из задач семейства clean, содержимое которой приведено в дампе 1.1. Ошибка возникала каждый раз после сборки пакета acl

Дамп 1.1

...
ERROR: acl-2.2.52-r0 do_clean: Error executing a python function in exec_python_func() autogenerated:

The stack trace of python calls that resulted in this exception/failure was:
File: 'exec_python_func() autogenerated', lineno: 2, function: 
     0001:
 *** 0002:do_clean(d)
     0003:
File: '/home/user/poky-building/poky/meta/classes/utility-tasks.bbclass', lineno: 29, function: do_clean
     0025:python do_clean() {
     0026:    """clear the build and temp directories"""
     0027:    dir = d.expand("${WORKDIR}")
     0028:    bb.note("Removing " + dir)
 *** 0029:    oe.path.remove(dir)
     0030:
     0031:    dir = "%s.*" % d.getVar('STAMP')
     0032:    bb.note("Removing " + dir)
     0033:    oe.path.remove(dir)
File: '/home/user/poky-building/poky/meta/lib/oe/path.py', lineno: 131, function: remove
     0127:        try:
     0128:            os.unlink(name)
     0129:        except OSError as exc:
     0130:            if recurse and exc.errno == errno.EISDIR:
 *** 0131:                shutil.rmtree(name)
     0132:            elif exc.errno != errno.ENOENT:
     0133:                raise
     0134:
     0135:def symlink(source, destination, force=False):
File: '/usr/lib/python3.5/shutil.py', lineno: 480, function: rmtree
     0476:            onerror(os.lstat, path, sys.exc_info())
     0477:            return
     0478:        try:
     0479:            if os.path.samestat(orig_st, os.fstat(fd)):
 *** 0480:                _rmtree_safe_fd(fd, path, onerror)
     0481:                try:
     0482:                    os.rmdir(path)
     0483:                except OSError:
     0484:                    onerror(os.rmdir, path, sys.exc_info())
File: '/usr/lib/python3.5/shutil.py', lineno: 422, function: _rmtree_safe_fd
     0418:                        _rmtree_safe_fd(dirfd, fullname, onerror)
     0419:                        try:
     0420:                            os.rmdir(name, dir_fd=topfd)
     0421:                        except OSError:
 *** 0422:                            onerror(os.rmdir, fullname, sys.exc_info())
     0423:                    else:
     0424:                        try:
     0425:                            # This can only happen if someone replaces
     0426:                            # a directory with a symlink after the call to
File: '/usr/lib/python3.5/shutil.py', lineno: 420, function: _rmtree_safe_fd
     0416:                try:
     0417:                    if os.path.samestat(orig_st, os.fstat(dirfd)):
     0418:                        _rmtree_safe_fd(dirfd, fullname, onerror)
     0419:                        try:
 *** 0420:                            os.rmdir(name, dir_fd=topfd)
     0421:                        except OSError:
     0422:                            onerror(os.rmdir, fullname, sys.exc_info())
     0423:                    else:
     0424:                        try:
Exception: OSError: [Errno 39] Directory not empty: 'pseudo'

ERROR: acl-2.2.52-r0 do_clean: Function failed: do_clean
ERROR: Logfile of failure stored in: /home/user/poky-building/poky/buildtmp/log/cleanlogs/acl/log.do_clean.18782
ERROR: Task (/home/user/poky-building/poky/meta/recipes-support/attr/acl_2.2.52.bb:do_clean) failed with exit code '1'
...

Из дампа 1.1 следует, что произошла ошибка запуска вышеупомянутой функции, написанной на Python. При этом тупые поиски в Инетернете по фразе "do_clean: Error executing a python function in exec_python_func() autogenerated" не приносили своих плодов, а лишь предлагали изменить шило-на-мыло или просто удалить полностью TMPFS, либо выполнить кучу sync’ов, которые результатов не приносили, как это будет показано ниже.

Давайте разберемся: Что на самом деле происходило? При более внимательном разборе строк дампа 1.1 и функции do_clean было выявлено, что ошибка произошла во время выполнения строчки 29 класса BB, meta/classes/utility-tasks.bbclass . При этом, как показано в дампе 1.2, в строке указанного класса BB, удаляемая рабочая директория полностью была распечатана.

Дамп 1.2

Build Configuration:
BB_VERSION           = "1.38.0"
BUILD_SYS            = "x86_64-linux"
NATIVELSBSTRING      = "universal"
TARGET_SYS           = "arm-poky-linux-gnueabi"
...
Initialising tasks...NOTE: Marking Active Tasks
NOTE: Pruned 4244 inactive tasks, 3 left
NOTE: Assign Weightings
NOTE: Compute totals (have 1 endpoint(s))
done.
NOTE: Executing RunQueue Tasks
NOTE: Running task 1 of 3 (/home/user/poky-building/poky/meta/recipes-support/attr/acl_2.2.52.bb:do_clean)
NOTE: recipe acl-2.2.52-r0: task do_clean: Started
NOTE: acl-2.2.52-r0 do_clean: Removing /home/user/poky-building/poky/buildtmp/work/armv5e-poky-linux-gnueabi/acl/2.2.52-r0
NOTE: recipe acl-2.2.52-r0: task do_clean: Failed
NOTE: Tasks Summary: Attempted 1 tasks of which 0 didn't need to be rerun and 1 failed.
...

В тоже время команда STAT(1) показала прекрасное самочувствие удалямой директории /home/user/poky-building/poky/buildtmp/work/armv5e-poky-linux-gnueabi/acl/2.2.52-r0, как показано в дампе 1.3

Дамп 1.3

...
$ stat /home/user/poky-building/poky/buildtmp/work/armv5e-poky-linux-gnueabi/acl/2.2.52-r0
  Файл: /home/user/poky-building/poky/buildtmp/work/armv5e-poky-linux-gnueabi/acl/2.2.52-r0
  Размер: 4096      	Блоков: 8          Блок В/В: 32768  каталог
Устройство: 2dh/45d	Inode: 41436558    Ссылки: 6
Доступ: (0755/drwxr-xr-x)  Uid: ( 1000/    user)   Gid: ( 1000/    user)
Доступ: 2020-11-24 11:20:31.108343535 +0300
Модифицирован: 2020-11-24 11:20:31.992210490 +0300
Изменён: 2020-11-24 11:20:31.992210490 +0300
 Создан: -
...

После чего, с использованием метода shutil.rmtree(dir) было установлено схожее поведение для oe.path.remove(dir), которое было явно связано с проблемой монтирования по NFS директории poky-building . Попытка заменить oe.path.remove(dir) на shutil.rmtree(dir), как показано в дампе 1.4 с треском провалилась, потому что ни один из файлов и ни одна поддиректория не были удалены из рабочей директории /home/user/poky-building/poky/buildtmp/work/armv5e-poky-linux-gnueabi/acl/2.2.52-r0

Дамп 1.4

...
 25 python do_clean() {
 26        import shutil
...  
 30        try:
 31              shutil.rmtree(dir)
 32        except Exception as e:
 33              bb.warn("SCA_EXPORT_FINDING_SRC-error: {}".format(e)) 
...

Полный цикл действий, приведший к ошибке "do_clean: Error executing a python function in exec_python_func() autogenerated", приведен в дампе 1.5

Дамп 1.5

DEBUG: Re-building acl: [cleansstate]     # bitbake -ccleansstate acl 
DEBUG: Re-building acl: [build] 	     # bitbake acl
DEBUG: Repeat Re-building acl: [sync]     # sync 
DEBUG: Repeat Re-building acl: [sync]     # sync
DEBUG: Repeat Re-building acl: [sync]     # sync
DEBUG: Repeat Re-building acl: [stat]     # stat ${WORKDIR}
DEBUG: Repeat Re-building acl: [lsof]     # lsof ${WORKDIR}
DEBUG: Repeat Re-building acl: [cleanall] # bitbake -ccleansstate acl
ERROR: acl-2.2.52-r0 do_clean: Error executing a python function in exec_python_func() autogenerated:
... /см. дамп 1.1/
ERROR: acl-2.2.52-r0 do_clean: Function failed: do_clean
ERROR: Logfile of failure stored in: /home/user/poky-building/poky/buildtmp/log/cleanlogs/acl/log.do_clean.17805
ERROR: Task (/home/user/poky-building/poky/meta/recipes-support/attr/acl_2.2.52.bb:do_clean) failed with exit code '1'
ERROR: failure.

2. Решение

Было связано с настройками монтирования на стороне клиента NFS, которые отвечают за кэширование атрибутов файлов и директорий, потому что клиент получает их из КЭШа и которые могут не соответствовать действительности, особенно, как показано в дампе 1.5, после цикла удаления, создания и попытки повторного удаления. Поэтому, чтобы избежать этого нужно как можно быстрее повторно запрашивать данные атрибуты с сервера NFS

Для этого можно воспользоваться опцией монтирования noac, которая предотвращает кэширование атрибутов файлов и директорий клиентом, что не совсем хорошо. Потому что кэширование атрибутов файлов и директорий клиентом производится некоторое число секунд путем опроса сервера NFS на предмет изменения атрибутов файлов и директорий. При этом, те изменения которые произошли на серверной стороне за короткий промежуток времени могут быть неопределенны, что и является ошибкой, приведенной в дампе 1.1

Далее, перед повторным выполнение задачи cleansstate была внесена задержка, равная ~80 секундам, и результат не заставил себя ждать, как показано в дампе 2.1

Дамп 2.1

DEBUG: Re-building acl: [cleansstate] 
DEBUG: Re-building acl: [build] 
DEBUG: Repeat Re-building acl: [sync] 
DEBUG: Repeat Re-building acl: [sync] 
DEBUG: Repeat Re-building acl: [sync] 
DEBUG: Repeat Re-building acl: [stat] 
  Файл: /home/user/poky-building/poky/buildtmp/work/armv5e-poky-linux-gnueabi/acl/2.2.52-r0
  Размер: 4096      	Блоков: 8          Блок В/В: 32768  каталог
Устройство: 2dh/45d	Inode: 41436558    Ссылки: 14
Доступ: (0755/drwxr-xr-x)  Uid: ( 1000/    user)   Gid: ( 1000/    user)
Доступ: 2020-11-24 13:49:47.957883739 +0300
Модифицирован: 2020-11-24 13:50:13.965957077 +0300
Изменён: 2020-11-24 13:50:13.965957077 +0300
 Создан: -
DEBUG: Repeat Re-building acl: [lsof] 
DEBUG: Waiting when the cache will be flushed for package "acl"
................................................................................
DEBUG: Repeat Re-building acl: [cleansstate] 
DEBUG: Repeat Re-building acl: done.

Конечно можно использовать опцию noac, который отключает подобное кэширование на стороне клиента NFS, но такой способ станет причиной удара по производительности, т.к. он позволяет снижать нагрузку на само сетевое соединение с сервером NFS за счет периодически обновляемого КЭШа.

Поэтому оптимальным считается использовать опцию actimeo=n на стороне клиента, который устанавливает в одно и тоже положение сразу несколько опций отвечающих за своевременное кэширование:

Исходя из приведенных значений, перед повторным выполнение задачи cleansstate была внесена задержка, равная ~80 секунд, которая превышает значительно максимально возможное время для хранения. Поэтому к правилу монтирования, приводимой в ранее для точки монтирования гостевой ВМ, добавляем опции "rsize=33554432,wsize=33554432,tcp,actimeo=1,timeo=10", что позволило снизить задержку до 30 секунд, как показано в дамп 2.2 .

Дамп 2.1

...
DEBUG: Repeat Re-building acl: [lsof] 
DEBUG: Waiting when the cache will be flushed for package "acl"
..............................
DEBUG: Repeat Re-building acl: [cleansstate] 
DEBUG: Repeat Re-building acl: done.

Конечно можно было полностью отключить ожидание обновления КЭШа путем установки timeo=0, что в нашем случае невозможно. Иначе, клинит клиент NFS и саму гостевую ВМ после запуска сборочной машины Yocto/poky. Кроме того, можно устанавить, как было показано в дампе 2.2, если не был ранее выставлен в оцпиях ядра размер 32МБ блокам данных, гоняемым через соединение по записи (wsize) и по чтению (rsize), а также максимальное время (timeo) в 100-х миллисекундных отсчетах (10 = 1 секунда) ожидания клиентом получения ответа от сервера NFS. Кстати, как установлено, значение timeo тоже влияет на обновление атрбутов файлов и директорий клиентом NFS.

3. Библиография

3.1 nfs(5) - Linux man page

3.2 Performance impact of disabling NFS attribute caching

3.3 Symantec.Recommended mount options for NFS

3.4 python os.path.exists() failing for nfs mounted directory file that exists

3.5 Doc_Functionality to Generate Digital Signature for Portugal(PT) Invoice Documents

3.6 How to delete a file or folder?

3.7 OS Path module in Python

3.8 Error executing a python function in exec_python_func()