Univention Bugzilla – Bug 31773
Updater tests fail "randomly"
Last modified: 2014-01-29 17:15:20 CET
The updater tests fail from time to time. It seems to be randomly at least the tests fail on different environments at different times, for example: Fail on memberserver #19: http://jenkins.knut.univention.de:8080/job/autotest/SambaVersion=s3,Systemrolle=member/19/testReport/%28root%29/09_updater_34updater-check/Test_the_correct_behavior_of_univention_updater_check/ Success on memberserver #18: http://jenkins.knut.univention.de:8080/job/autotest/SambaVersion=s3,Systemrolle=member/18/testReport/%28root%29/09_updater_34updater-check/Test_the_correct_behavior_of_univention_updater_check/ Other examples: http://jenkins.knut.univention.de:8080/job/autotest/17/SambaVersion=s3,Systemrolle=master/testReport/junit/%28root%29/09_updater_28errors/Update_localhost_repository_testing_errors_1__setup_local_repository_with_1_update_2__check_if_upgrade_of_package_work_3__check_if___updateto_is_honored/ http://jenkins.knut.univention.de:8080/job/autotest/17/SambaVersion=s4,Systemrolle=backup/testReport/junit/%28root%29/09_updater_16proxy-auth/Update_localhost_repository_via_authorized_proxy_1__Use_minimal_proxy_implemented_in_Python/
Post-processing memo: :%s/test-\d\{3,5\}-\d\{3,5\}/test-0000-0000/g :%s/\<\(user\|test\)\d\{3,5\}/\10000/g svn41733: Disable cron during updater tests. http://jenkins.knut.univention.de:8080/job/ucs-test_BUILD/317/
09_updater/34updater-check still fails sometimes: http://jenkins.knut.univention.de:8080/view/Autotest/job/UCS%203.2%20Autotest%20MultiEnv/SambaVersion=s3,Systemrolle=member/lastCompletedBuild/testReport/%28root%29/09_updater_34updater-check/Test_the_correct_behavior_of_univention_updater_check/
While "dpkg -l" reports version 5 of the test package to be already installed and configured, "apt-cache policy" still thinks it is version 4. During the simulated update the package is found and update/available=yes is set. # while UT_DELAY=30 ./34updater-check -v -f ; do :; done ^Z # dpkg-query -W test-6102-\* test-6102-13144 5 # LANG=C apt-cache policy test-6102-\* test-6102-13144: Installed: 4 Candidat: 5 Version table: 5 0 500 http://localhost/univention-repository/3.2/maintained 3.2-2/amd64/ Packages *** 4 0 100 /var/lib/status 3 0 500 http://localhost/univention-repository/3.2/maintained 3.2-1/amd64/ Packages 1 0 500 http://localhost/univention-repository/3.2/maintained 3.2-0/amd64/ Packages # touch /var/lib/dpkg/status #OR# rm /var/cache/apt/pkgcache.bin # LANG=C apt-cache policy test-6102-\* test-6102-13144: Installed: 5 Candidat: 5 Version table: *** 5 0 500 http://localhost/univention-repository/3.2/maintained 3.2-2/amd64/ Packages 100 /var/lib/status 3 0 500 http://localhost/univention-repository/3.2/maintained 3.2-1/amd64/ Packages 1 0 500 http://localhost/univention-repository/3.2/maintained 3.2-0/amd64/ Packages # dpkg -S /usr/lib/libapt-pkg.so.4.10 apt: /usr/lib/libapt-pkg.so.4.10 # dpkg-query -W apt apt 0.8.10.3.54.201210100846 That's a timing condition in APT: # inotifywait --format '%T %w %e %f' --timefmt '%H:%M:%S' -m \ -e close_write -e open -e move -e create -e delete \ /var/cache/apt /var/lock /var/lib/dpkg ... 15:43:50 /var/cache/apt/ OPEN pkgcache.bin 15:43:50 /var/lib/dpkg/ OPEN status ... 15:43:51 /var/lib/dpkg/ CREATE status-new 15:43:51 /var/lib/dpkg/ OPEN status-new 15:43:51 /var/lib/dpkg/ CLOSE_WRITE,CLOSE status-new ... 15:43:51 /var/lib/dpkg/ MOVED_FROM status-new 15:43:51 /var/lib/dpkg/ MOVED_TO status ... 15:43:51 /var/cache/apt/ OPEN pkgcache.bin 15:43:51 /var/cache/apt/ DELETE pkgcache.bin 15:43:51 /var/cache/apt/ CREATE pkgcache.bin.llBDbq 15:43:51 /var/cache/apt/ OPEN pkgcache.bin.llBDbq 15:43:51 /var/lib/dpkg/ OPEN status 15:43:51 /var/cache/apt/ MOVED_FROM pkgcache.bin.llBDbq 15:43:51 /var/cache/apt/ MOVED_TO pkgcache.bin 15:43:51 /var/lib/dpkg/ OPEN status ... 15:43:51 /var/cache/apt/ OPEN pkgcache.bin ... 15:43:51 /var/lib/dpkg/ OPEN status ... 15:43:51 /var/lib/dpkg/ CREATE status-new 15:43:51 /var/lib/dpkg/ OPEN status-new 15:43:51 /var/lib/dpkg/ CLOSE_WRITE,CLOSE status-new ... 15:43:51 /var/lib/dpkg/ MOVED_FROM status-new 15:43:51 /var/lib/dpkg/ MOVED_TO status ... 15:43:51 /var/lib/dpkg/ CREATE status-new 15:43:51 /var/lib/dpkg/ OPEN status-new 15:43:51 /var/lib/dpkg/ CLOSE_WRITE,CLOSE status-new ... 15:43:51 /var/lib/dpkg/ MOVED_FROM status-new 15:43:51 /var/lib/dpkg/ MOVED_TO status ... 15:43:52 /var/cache/apt/ CLOSE_WRITE,CLOSE pkgcache.bin ... For efficiency APT parses the text file /var/lib/dpkg/status and creates a memory-mapped version /var/cache/apt/pkgcache.bin for caching. The file contains a time stamp to detect updated versions of the status file, but the time stamp only used *seconds granularity*. In some situations (especially VMs with virtual HDs) dpkg is too fast and updates the status file multiple times a second. In this case the cache gets stale and only contains the previous information, where version 4 was successfully configured. APTs source is here: <http://anonscm.debian.org/gitweb/?p=apt/apt.git;a=history;f=apt-pkg;hb=HEAD> apt-pkg/pkgcache.cc:854 if (Buf.st_size != (signed)S->Size || Buf.st_mtime != S->mtime) apt-pkg/deb/debindexfile.cc:358 if ((unsigned)St.st_size != File->Size || St.st_mtime != File->mtime) Possible solutions: 1. add nanosecond resolution (man 2 stat → tv_nsec) 2. add artificial 1 second delay in apt-dpkg-interaction
A specific workaround was added to the 09/34 test to retry the failed command until APT is fixed. Debian-Bug: <http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=715494> svn42210+42211 ucs-test_4.0.60-1.516.201307091806 No ChangeLog, no YAML
OK, it works now.
It happened again: http://jenkins.knut.univention.de:8080/view/Autotest/job/UCS%203.2%20Autotest%20MultiEnv/183/SambaVersion=s4,Systemrolle=member/testReport/%28root%29/09_updater_28errors/Update_localhost_repository_testing_errors_1__setup_local_repository_with_1_update_2__check_if_upgrade_of_package_work_3__check_if___updateto_is_honored/ http://jenkins.knut.univention.de:8080/view/Autotest/job/UCS%203.2%20Autotest%20MultiEnv/183/SambaVersion=s4,Systemrolle=member/testReport/%28root%29/09_updater_34updater-check/Test_the_correct_behavior_of_univention_updater_check/ http://jenkins.knut.univention.de:8080/view/Autotest/job/UCS%203.2%20Autotest%20MultiEnv/183/SambaVersion=s4,Systemrolle=member/testReport/%28root%29/09_updater_37version-max/Update_localhost_repository_at_max_version_1__Set_version_to_99_99_99_999_2__Setup_local_repository_with_next_major__minor__patch_level_2__Check_if_updater_skips_these_updates/
Cron-jobs have been disabled for ucs-ec2-tools, since they may have been started way before ucs-test even begins to run. r45730 | Bug #31773: ucs-test: disable cron jobs Package is currently not buildable because of previous existing errors: E:0010-2: examples/jenkins/utils/schoolinstaller.py: file contains no copyright text block E:0010-2: examples/jenkins/utils/utils.lib: file contains no copyright text block E:0009-2: examples/jenkins/utils/schoolinstaller.py: file does not specify python version in hashbang
*** Bug 33009 has been marked as a duplicate of this bug. ***
r45745 | Bug #31773: ucs-test: re-enable UCR cron jobs Removed cron/ucrdisabled=true to re-enable cron-jobs defined through UCR. Not build.
(In reply to Philipp Hahn from comment #9) > r45745 | Bug #31773: ucs-test: re-enable UCR cron jobs > Removed cron/ucrdisabled=true to re-enable cron-jobs defined through UCR. > Not build. OK, looks good. Changelog: OK
UCS 3.2 has been released: http://docs.univention.de/release-notes-3.2-en.html http://docs.univention.de/release-notes-3.2-de.html If this error occurs again, please use "Clone This Bug".
*** Bug 29368 has been marked as a duplicate of this bug. ***