Дата и время публикации:
Проблемы и решение
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 на стороне клиента, который устанавливает в одно и тоже положение сразу несколько опций отвечающих за своевременное кэширование:
- Опция acregmin=n и acregmax=n устанавливает максимальное и минимальное время в секундах сколько клиент NFS держит атрибуты регулярного файла у себя в КЭШе до того момента, когда будет получена более свежая информация о них от сервера. Минимальное время хранения атрибутов устанавливается значение, равное 3-секундам, а максимальное — 60 секунд.
- Опция acdirmin=n и acdirmax=n устанавливает максимальное и минимальное время в секундах сколько клиент NFS держит атрибуты директории у себя в КЭШе до того момента, когда будет получена более свежая информация о них от сервера. Минимальное время хранения атрибутов устанавливается значение, равное 30-секунд, а максимальное — 60 секунд.
Исходя из приведенных значений, перед повторным выполнение задачи 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.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