Just so you know, there is no conclusion to this story. The cause is still not known. However, I have some ideas to track it down and a follow-up blog post is underway.
In short:
- All src commits gave errors – this was reproducible, and has been fixed
- When an error occurs, it’s not the same commits on both dev and test – they are not reproducible
- Comparing the log for a given commit under Perl 5.40 and 5.38 are the same
- When rerunning the commit, the error does not occur – the errors are not reproducible
- If a commit has errored, and it is rerun without error, the logs show no clues as to cause – they are effectively identical (time stamps and hostnames excepted)
- My current idea: put a database onto a separate ZFS filesystem and snapshot it. See if there is some database issue causing the error
On Saturday morning, I noticed a new message in the logs:
Checking for packages with security vulnerabilities: Database fetched: 2025-05-15T21:00+00:00 perl5-5.38.4_1: Tag: expiration_date Value: 2026-07-03 perl5-5.38.4_1: Tag: deprecated Value: Support end three years after .0 release, please upgrade to a more recent version of Perl
OK, let’s update. I modified my poudriere build configuration so it built perl 5.40:
[12:44 pkg01 dvl /usr/local/etc/poudriere.d] % svn di default-make.conf Index: default-make.conf =================================================================== --- default-make.conf (revision 20947) +++ default-make.conf (working copy) @@ -80,7 +80,7 @@ # # So let's try ssl=base # -DEFAULT_VERSIONS= pgsql=16 php=83 ssl=base perl5=5.38 +DEFAULT_VERSIONS= pgsql=16 php=83 ssl=base perl5=5.40 #sysutils_anvil_UNSET+=CURL #sysutils_anvil_UNSET+=FETCH [12:44 pkg01 dvl /usr/local/etc/poudriere.d] %
Then rebuilt:
sudo poudriere bulk -j 142amd64 -p default -z primary -f /usr/local/etc/poudriere.d/buildlists/primary
In this post:
- FreeBSD 14.2
- poudriere-3.4.2
- perl-5.38
- perl-5.40
The install
After the build, I ran pkg upgrade on three hosts:
- empty
- dvl-ingress01
- test-ingress01
This shows you what got upgraded/installed:
[12:47 test-ingress01 dvl ~] % grep pkg /var/log/messages | grep 'May 17' May 17 13:27:34 test-ingress01 pkg[98127]: perl5-5.40.2_2 installed May 17 13:27:34 test-ingress01 pkg[98127]: groff-1.23.0_4 installed May 17 13:27:34 test-ingress01 pkg[98127]: mysql80-client-8.0.42 installed May 17 13:27:34 test-ingress01 pkg[98127]: nagios-check_postgres-2.26.0 installed May 17 13:27:35 test-ingress01 pkg[98127]: nagios-plugins-2.4.4,1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Algorithm-C3-0.11 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Carp-Clan-6.08 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Bit-Vector-7.4_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Class-C3-0.35 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Class-ISA-0.36_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Class-Method-Modifiers-2.15 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Class-Observable-2.004 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Clone-0.47 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-DBI-1.647 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-DBD-Pg-3.18.0 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Date-Calc-6.4 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Devel-StackTrace-2.05 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Digest-HMAC-1.05 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Authen-NTLM-1.09_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-Address-1.913 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-Address-XS-1.05 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-Date-Format-1.008 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-MIME-Encodings-1.317 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-MessageID-1.408 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-Simple-2.218 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Encode-Locale-1.05 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Error-0.17030 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Exporter-Tiny-1.006002 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-File-Type-0.22_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-HTML-Tagset-3.24 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-IO-HTML-1.004 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-IO-Socket-IP-0.43 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-IO-String-1.08_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-IPC-Signal-1.00_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-LWP-MediaTypes-6.04 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-List-MoreUtils-XS-0.430 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-List-MoreUtils-0.430 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-MIME-Types-2.28 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-MRO-Compat-0.15 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Module-Pluggable-5.2 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-Abstract-3.010 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Module-Runtime-0.017 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-MooX-Types-MooseLike-0.29 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Mozilla-CA-20250202 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Net-SSLeay-1.94 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-IO-Socket-SSL-2.089 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Params-Util-1.102 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Proc-WaitStat-1.00_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: mime-construct-1.11_2 installed May 17 13:27:35 test-ingress01 pkg[98127]: logcheck-1.4.4_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Role-Tiny-2.002004 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Sub-Install-0.929 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Data-OptList-0.114 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Sub-Exporter-0.991 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Text-Unidecode-1.30 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-MIME-ContentType-1.028 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-MIME-1.954 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Text-Wrapper-1.05 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-TimeDate-2.33,1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-HTTP-Date-6.06 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-File-Listing-6.16 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Try-Tiny-0.32 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-URI-5.32 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-HTTP-Message-7.00 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-HTML-Parser-3.83 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-CGI-4.68 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-HTTP-Cookies-6.11 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-HTTP-Negotiate-6.01_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Net-HTTP-6.23 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Unix-Syslog-1.1_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-WWW-RobotRules-6.02_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-XML-Parser-2.47 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-XML-Node-0.11_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-XML-RegExp-0.04_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-XML-Writer-0.900 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-XML-XPathEngine-0.14_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-XString-0.005 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Sub-Quote-2.006008_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Moo-2.005005 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Throwable-1.001 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-Sender-2.601 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-Email-Stuffer-0.020 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-libwww-6.78 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-freshports-modules-2.1.2 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-libxml-0.08_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-XML-DOM-1.46 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-XML-DOM-XPath-0.14_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-freshports-scripts-2.1.1 installed May 17 13:27:35 test-ingress01 pkg[98127]: freshports-freshports-2.0.15_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: freshports-ingress-2.0.4_13 installed May 17 13:27:35 test-ingress01 pkg[98127]: p5-freshports-verify-2.0.10_1 installed May 17 13:27:35 test-ingress01 pkg[98127]: pflogsumm-1.1.5_2,1 installed
The aftermath
This morning, I awoke to find some nagios notifications:
I logged into dvl-ingress01 and had a look.
Typically, they contain this:
[12:52 test-ingress01 dvl ~freshports/message-queues/recent] % cat 2025.05.18.03.14.42.000005.72e50977a616490b7fe634ef32a7a19bd35cd62d.errors
DBI db handle 0x1f9c7da484b0 has 1 uncleared child handles during global destruction.
dbih_clearcom (dbh 0x1f9c7da484b0, com 0x1f9c7d1a8700, imp DBD::Pg::db):
FLAGS 0x180111: COMSET Warn PrintError PrintWarn
PARENT DBI::dr=HASH(0x1f9c7da49690)
KIDS 1 (0 Active)
It sounds like the code is missing a destroy. This may not be trivial to locate. Some of this code is 25 years old.
Checking a src commit
I checked the commits; one of them was for src, not ports. Given that non-ports tree commits are less work than ports, I’ll follow that trail.
The commit in question is:
[12:55 dvl-ingress01 dvl ~freshports/message-queues/recent] % cat 2025.05.18.09.21.14.000000.89549c2348170921cc4270ac95bfabfd78d42739.xml
<?xml version='1.0' encoding='UTF-8'?>
<UPDATES Version="1.5.0.0" Source="git">
<UPDATE>
<DATE Year="2025" Month="5" Day="18"/>
<TIME Timezone="UTC" Hour="9" Minute="21" Second="14"/>
<OS Repo="src" Id="FreeBSD" Branch="main"/>
<LOG>nullfs lookup: cn_flags is 64bit
Reviewed by: olce
Sponsored by: The FreeBSD Foundation
MFC after: 1 week
Differential revision: https://reviews.freebsd.org/D50390</LOG>
<PEOPLE>
<COMMITTER CommitterName="Konstantin Belousov" CommitterEmail="kib@FreeBSD.org"/>
<AUTHOR AuthorName="Konstantin Belousov" AuthorEmail="kib@FreeBSD.org"/>
</PEOPLE>
<COMMIT Hash="89549c2348170921cc4270ac95bfabfd78d42739" HashShort="89549c2" Subject="nullfs lookup: cn_flags is 64bit" EncodingLoses="false" Repository="src"/>
<FILES>
<FILE Action="Modify" Path="sys/fs/nullfs/null_vnops.c"/>
</FILES>
</UPDATE>
</UPDATES>
[12:56 dvl-ingress01 dvl ~freshports/message-queues/recent] %
Let’s see if I can reproduce the problem. First, delete the commit from the database.
[12:58 pg03 dvl ~] % psql freshports.dvl psql (16.9) Type "help" for help. freshports.dvl=# begin; delete from commit_log where message_id = '89549c2348170921cc4270ac95bfabfd78d42739'; BEGIN DELETE 1 freshports.dvl=*# commit; COMMIT freshports.dvl=#
I will do the above before each test run, but I won’t show it in this post.
Rerun the commit processing:
[13:01 dvl-ingress01 dvl ~freshports/message-queues/recent] % echo /usr/local/bin/perl /usr/local/libexec/freshports/load_xml_into_db.pl /var/db/freshports/message-queues/recent/2025.05.18.09.21.14.000000.89549c2348170921cc4270ac95bfabfd78d42739.xml | sudo su -fm freshports
grabbing categories from disk
'accessibility arabic archivers astro audio benchmarks biology cad chinese comms converters databases deskutils devel distfiles dns editors emulators filesystems finance french ftp games german graphics hebrew hungarian irc japanese java korean lang mail math misc multimedia net net-im net-mgmt net-p2p news polish ports-mgmt portuguese print russian science security shells sysutils textproc ukrainian vietnamese www x11 x11-clocks x11-drivers x11-fm x11-fonts x11-servers x11-themes x11-toolkits x11-wm'
about to process
finished setting up the Parser
Processing file [/var/db/freshports/message-queues/recent/2025.05.18.09.21.14.000000.89549c2348170921cc4270ac95bfabfd78d42739.xml]...
parsing file now
*** start of all updates ***
*** end of all updates ***
source in getSource is 'git'
That commit is of Type: 'git'
EOF
invoking XML_Munge_git because this is a git commit
about to process
Observer has noticed that processing has begun.
finished setting up the Parser
Processing file [/var/db/freshports/message-queues/recent/2025.05.18.09.21.14.000000.89549c2348170921cc4270ac95bfabfd78d42739.xml]...
dbname = freshports.dvl
parsing file now
*** start of all updates ***
--- start of an update ---
--- end of OS ---
OS is 'FreeBSD' : branch = 'main' for git
after converting '$Updates{branch_git}' we have 'head'
next we need to strip any leading 'branches/' prefix
OS is 'FreeBSD' : branch = 'main' for git
OS is 'FreeBSD' : branch = 'head' for git
OS is 'FreeBSD' : branch = 'head' for database names
sql = 'select SystemIDGet('FreeBSD')'
SystemBranchIDGetOrCreate has converted 'head' to 'head' which will be used in the database
sql = 'select SystemBranchIDGet(1, 'head')'
OS is 'FreeBSD' (1) : branch = head (1)
found Committer= [kib]
found Author= [Konstantin Belousov]
OS = [FreeBSD]
Branch git = [main]
branch_database_name = [head]
branch_for_files = [head]
Committer = [kib]
Date = [2025/05/18 09:21:14 UTC]
Repository = [src]
Revision = [89549c2348170921cc4270ac95bfabfd78d42739]
MessageId = [89549c2348170921cc4270ac95bfabfd78d42739]
short hash = [89549c2]
Subject = [nullfs lookup: cn_flags is 64bit]
Log = [nullfs lookup: cn_flags is 64bit
Reviewed by: olce
Sponsored by: The FreeBSD Foundation
MFC after: 1 week
Differential revision: https://reviews.freebsd.org/D50390]
into handle_message_end, let's save that message now!
xml_munge_git.pm::SaveUpdateToDB --- start
GetExistingMessageID => sql=select id from commit_log where message_id = '89549c2348170921cc4270ac95bfabfd78d42739'
$this->{repo} = 'src'
$this->{repository} = 'git'
Quoting the above we get:
'src' and repository = 'git'
sql is insert into commit_log (id, message_id, message_date, message_subject, date_added, commit_date,
committer, committer_name, committer_email, author_name, author_email, description, system_id, svn_revision, repo_id, encoding_losses, commit_hash_short) values (
?,
?,
?,
?,
now(),
?,
?,
?,
?,
?,
?,
?,
?,
?,
(SELECT id FROM repo WHERE name = ? and repository = ?),
?::boolean,
?)
saving commit_log <-> branch information
sql is SELECT CommitLogBranchesInsert(1071632, 1)
we have saved with id = '1071632'
Observer has noticed that commit '89549c2348170921cc4270ac95bfabfd78d42739' has been saved with a commit log id of 1071632. Thank you.
xml_munge_git.pm::SaveUpdateToDB --- finish
commit_hash = '89549c2348170921cc4270ac95bfabfd78d42739'
Updates{FileRevision} = '89549c2348170921cc4270ac95bfabfd78d42739'
FileRevision = '89549c2348170921cc4270ac95bfabfd78d42739'
File = [Modify : /base/head/sys/fs/nullfs/null_vnops.c : 89549c2348170921cc4270ac95bfabfd78d42739]
FileActionValid ==> M
sql = 'select Pathname_ID('/base/head/sys/fs/nullfs/null_vnops.c')'
Element::FetchByName - here is what that SQL returned
Element::FetchByName found: 79571
done....
I found this element id for that pathname: 79571
That element revision already exists; not adding it
saving commit_log_element
$FreshPorts::Constants::commit_log_seq='commit_log_id_seq'
$FreshPorts::Constants::ports_seq='ports_id_seq'
$FreshPorts::Constants::commit_log_elements_seq='commit_log_elements_id_seq'
commit_log_element::save..........
$FreshPorts::Constants::commit_log_seq='commit_log_id_seq'
$FreshPorts::Constants::ports_seq='ports_id_seq'
$FreshPorts::Constants::commit_log_elements_seq='commit_log_elements_id_seq'
getting id from 'commit_log_elements_id_seq'
sql is insert into commit_log_elements(id, commit_log_id, element_id, revision_name, change_type) values
(5547774, 1071632, 79571, '89549c2348170921cc4270ac95bfabfd78d42739', 'M')
sql = 'select ElementTagSet(1, 79571, '89549c2348170921cc4270ac95bfabfd78d42739')'
pushing the following onto @Files
FileAction='Modify'
FilePath='/base/head/sys/fs/nullfs/null_vnops.c'
FileRevision='89549c2348170921cc4270ac95bfabfd78d42739'
commit_log_element->{id}='5547774'
element_id='79571'
Observer has noticed that commit '89549c2348170921cc4270ac95bfabfd78d42739' contains file /base/head/sys/fs/nullfs/null_vnops.c as revision 89549c2348170921cc4270ac95bfabfd78d42739 in repository src
No errors found during that commit
Observer has noticed that the update for 89549c2348170921cc4270ac95bfabfd78d42739 has finished.
Observer will clear the following ports from cache after the commit:
Observer will clear the following files from cache after the commit:
/base/head/sys/fs/nullfs/null_vnops.c
*** end of items to be cleared
*** end of all updates ***
Observer has noticed that processing has finished.
now is the commit:
Observer has noticed that a transaction has been committed.
# # # # Removing files from the cache # # # #
/base/head/sys/fs/nullfs/null_vnops.c
sql is insert into cache_clearing_files (pathname) values ('/base/head/sys/fs/nullfs/null_vnops.c')
ON CONFLICT ON CONSTRAINT cache_clearing_files_pathname DO NOTHING
# # # # Finished: Removing files from the cache # # # #
EOF
DBI db handle 0x1a123cd425b8 has 1 uncleared child handles during global destruction.
dbih_clearcom (dbh 0x1a123cd425b8, com 0x1a123c3a45c0, imp DBD::Pg::db):
FLAGS 0x180111: COMSET Warn PrintError PrintWarn
PARENT DBI::dr=HASH(0x1a123cd43798)
KIDS 1 (0 Active)
[13:01 dvl-ingress01 dvl ~freshports/message-queues/recent] %
There we go. A reproducible situation. That’s always the first step. Now we’ll know if we fixed if any changes are made.
Stop stuff
If I’m going to be mucking about with code, let’s stop the usual processing for now:
[13:04 dvl-ingress01 dvl ~] % sudo service ingress stop Stopping ingress. Waiting for PIDS: 3196. [13:04 dvl-ingress01 dvl ~] % sudo service freshports stop Stopping freshports. Waiting for PIDS: 3214. [13:04 dvl-ingress01 dvl ~] % sudo touch /var/db/freshports/signals/OFFLINE [13:05 dvl-ingress01 dvl ~] %
That last line is a signal to cronjobs/periodic scripts that things are offline, don’t run. They’ll check for that file on start-up.
Tracking it down
Looking at the freshport.sh script (from the freshports service, stopped above), I see it invokes load_xml_into_db.pl – let’s comment out a line in there.
File load_xml_into_db.pl saved [13:10 dvl-ingress01 dvl ~/scripts] % svn di Index: load_xml_into_db.pl =================================================================== --- load_xml_into_db.pl (revision 6132) +++ load_xml_into_db.pl (working copy) @@ -101,7 +101,7 @@ $Munger->add_observer($ObserverCommits); print "about to process\n"; - $ErrorFound = $Munger->process(); +# $ErrorFound = $Munger->process(); print " now is the commit:\n";
Running the script again (after first deleting the commit from the database again), we get different results:
[13:01 dvl-ingress01 dvl ~freshports/message-queues/recent] % echo /usr/local/bin/perl /usr/local/libexec/freshports/load_xml_into_db.pl /var/db/freshports/message-queues/recent/2025.05.18.09.21.14.000000.89549c2348170921cc4270ac95bfabfd78d42739.xml | sudo su -fm freshports grabbing categories from disk 'accessibility arabic archivers astro audio benchmarks biology cad chinese comms converters databases deskutils devel distfiles dns editors emulators filesystems finance french ftp games german graphics hebrew hungarian irc japanese java korean lang mail math misc multimedia net net-im net-mgmt net-p2p news polish ports-mgmt portuguese print russian science security shells sysutils textproc ukrainian vietnamese www x11 x11-clocks x11-drivers x11-fm x11-fonts x11-servers x11-themes x11-toolkits x11-wm' about to process finished setting up the Parser Processing file [/var/db/freshports/message-queues/recent/2025.05.18.09.21.14.000000.89549c2348170921cc4270ac95bfabfd78d42739.xml]... parsing file now *** start of all updates *** *** end of all updates *** source in getSource is 'git' That commit is of Type: 'git' EOF invoking XML_Munge_git because this is a git commit about to process now is the commit: Observer has noticed that a transaction has been committed. This commit had no files that need to be removed from the cache EOF [13:10 dvl-ingress01 dvl ~freshports/message-queues/recent] %
Next, I’ll repeat a similar process within xml_munge_git.pm and see how quickly I can track down this bug.
Huh. I just tried rerunning the commit without deleting from the database first. It reproduces the error.
[13:29 dvl-ingress01 dvl ~freshports/message-queues/recent] % echo /usr/local/bin/perl /usr/local/libexec/freshports/load_xml_into_db.pl /var/db/freshports/message-queues/recent/2025.05.18.09.21.14.000000.89549c2348170921cc4270ac95bfabfd78d42739.xml | sudo su -fm freshports
grabbing categories from disk
'accessibility arabic archivers astro audio benchmarks biology cad chinese comms converters databases deskutils devel distfiles dns editors emulators filesystems finance french ftp games german graphics hebrew hungarian irc japanese java korean lang mail math misc multimedia net net-im net-mgmt net-p2p news polish ports-mgmt portuguese print russian science security shells sysutils textproc ukrainian vietnamese www x11 x11-clocks x11-drivers x11-fm x11-fonts x11-servers x11-themes x11-toolkits x11-wm'
about to process
finished setting up the Parser
Processing file [/var/db/freshports/message-queues/recent/2025.05.18.09.21.14.000000.89549c2348170921cc4270ac95bfabfd78d42739.xml]...
parsing file now
*** start of all updates ***
*** end of all updates ***
source in getSource is 'git'
That commit is of Type: 'git'
EOF
invoking XML_Munge_git because this is a git commit
about to process
Observer has noticed that processing has begun.
finished setting up the Parser
Processing file [/var/db/freshports/message-queues/recent/2025.05.18.09.21.14.000000.89549c2348170921cc4270ac95bfabfd78d42739.xml]...
dbname = freshports.dvl
parsing file now
*** start of all updates ***
--- start of an update ---
--- end of OS ---
OS is 'FreeBSD' : branch = 'main' for git
after converting '$Updates{branch_git}' we have 'head'
next we need to strip any leading 'branches/' prefix
OS is 'FreeBSD' : branch = 'main' for git
OS is 'FreeBSD' : branch = 'head' for git
OS is 'FreeBSD' : branch = 'head' for database names
sql = 'select SystemIDGet('FreeBSD')'
SystemBranchIDGetOrCreate has converted 'head' to 'head' which will be used in the database
sql = 'select SystemBranchIDGet(1, 'head')'
OS is 'FreeBSD' (1) : branch = head (1)
found Committer= [kib]
found Author= [Konstantin Belousov]
OS = [FreeBSD]
Branch git = [main]
branch_database_name = [head]
branch_for_files = [head]
Committer = [kib]
Date = [2025/05/18 09:21:14 UTC]
Repository = [src]
Revision = [89549c2348170921cc4270ac95bfabfd78d42739]
MessageId = [89549c2348170921cc4270ac95bfabfd78d42739]
short hash = [89549c2]
Subject = [nullfs lookup: cn_flags is 64bit]
Log = [nullfs lookup: cn_flags is 64bit
Reviewed by: olce
Sponsored by: The FreeBSD Foundation
MFC after: 1 week
Differential revision: https://reviews.freebsd.org/D50390]
into handle_message_end, let's save that message now!
xml_munge_git.pm::SaveUpdateToDB --- start
GetExistingMessageID => sql=select id from commit_log where message_id = '89549c2348170921cc4270ac95bfabfd78d42739'
message 89549c2348170921cc4270ac95bfabfd78d42739 has already been added to the database
no commit id returned. we'll just exit now shall we?
DBI dr handle 0x396bf8949798 cleared whilst still active during global destruction.
dbih_clearcom (drh 0x396bf8949798, com 0x396bf7f1d380, imp DBD::Pg::dr):
FLAGS 0x100215: COMSET Active Warn PrintWarn AutoCommit
PARENT undef
KIDS 0 (1 Active)
[13:29 dvl-ingress01 dvl ~freshports/message-queues/recent] %
That cuts out a whole section of code.
I found I could do this and all seems well:
[13:49 dvl-ingress01 dvl ~/modules] % svn di
Index: xml_munge_git.pm
===================================================================
--- xml_munge_git.pm (revision 6144)
+++ xml_munge_git.pm (working copy)
@@ -897,8 +897,15 @@
$commit_log_id = SaveUpdateToDB();
}
+ # Let's found avoid: DBI::db=HASH(0x348838f41618)->disconnect invalidates 1 active statement handle (either destroy statement handles or
+ # call finish on them before disconnecting) at /usr/local/lib/perl5/site_perl/FreshPorts/xml_munge_git.pm line 902.
+ # if no commit log id is returned.
+ $sth->finish();
if (!defined(commit_log_id())) {
print "no commit id returned. we'll just exit now shall we?\n";
+ # We are exiting here, let's destroy this and avoid:
+ # DBI dr handle 0x340f309447c8 cleared whilst still active during global destruction
+ $self->{dbh}->disconnect();
exit 0;
}
}
[13:50 dvl-ingress01 dvl ~/modules] %
This fixes the original problem for the src commit. Let’s see if I can reproduce the problem for the ports commit.
Monday morning
By the time I finished exploring the problem yesterday (Sunday), I was unable to reproduce the problem. This morning, there are two more errored commits, both of the in the src tree. Deleting and redoing the commits does not reproduce the error.
That makes tracking down the bug difficult. If you can’t reproduce the problem, you can’t know it’s fixed.
However, there are no errors on the test website. I have no idea why that’s not getting errors, given no changes have been made there since the error first appeared.
