Jochen Neumeister noticed that FreshPorts no longer lists phpunit6.
see also https://github.com/FreshPorts/freshports/issues/72.
Sure enough, I went searching and failed to find it. It did not turn up.
Then I checked Include deleted ports, then clicked on Search again. Ahh, there it it.
Sure enough, it is marked as deleted. Look for the small icon at the top, just to the right of the category name. It looks like a tombstone with RIP written on it.
Rene Laden mentioned that FreshPorts is confused after r437302 on 30 Mar 2017 15:03:16. That commit message was Recreate port devel/phpunit6 as repo-copy of devel/phpunit. The previous commit was Remove devel/phpunit6 for direct recreation as repo-copy
at 30 Mar 2017 15:01:26.
Those commits are:
- remove – 437301 – 201703301501.v2UF1QU6020080@repo.freebsd.org
- recreate – 437302 – 201703301503.v2UF3GuI022547@repo.freebsd.org
Note that the recreate occurred two minutes after the remove.
What does the log say?
I know FreshPorts can handle a port being deleted. I know it can handle a port being committed to after it is deleted. Let’s find out what happened.
$ cd /usr/FreshPorts/freshports.org/msgs/FreeBSD/archive/2017_03/2017_03_30 $ $ # this is the remove message $ $ grep -l 'svn commit: r437301' * 2017.03.30.15.10.13.14518.txt.loading 2017.03.30.15.10.13.14518.txt.raw 2017.03.30.15.10.13.14518.txt.xml $ $ # this is the add message $ $ grep -l 'svn commit: r437302' * 2017.03.30.15.03.21.25140.txt.loading 2017.03.30.15.03.21.25140.txt.raw 2017.03.30.15.03.21.25140.txt.xml
The file name has the following format: YYYY.MM.DD.HH.MM.SS.process_id.
The timestamp in the file name represents the time at which the incoming email was saved to the queue. Incoming commits are processed in the order in which they arrive at the FreshPorts server.
In this case, the create was processed at 15:03, a full seven minutes before the remove was processed at 15:10.
Clearly, the add was processed before the delete. This doesn’t bother FreshPorts. It can’t tell.
From the logs of the remove, I found:
# # # # Resurrecting deleted ports # # # # found a deleted port: port='phpunit6', port_id='41762', element_id='789692' now looking for files which were modified... inspecting: 'Remove', '/ports/head/devel/phpunit6/', '437301', '', 'ports', 'devel/phpunit6/' finished looking through the files # # # # Finished resurrecting deleted ports # # # #
I had to think about this slowly.
We are in a port remove, and we are resurrecting a deleted port. How did that port get deleted? Or more precisely, why did FreshPorts think it was deleted and needed resurrecting? This is the only commit which was doing a delete. This commit *is* the remove.
However, even if the commits were processed out of order, this is what I think should have happened:
- the Create gets processed: all good
- the Remove is processed: port is marked as deleted
- another commit gets processed: port is resurrected and everything is fine
My question is: why is devel/phpunit6 still marked as deleted?
Let’s look farther into this.
The subsequent commits
The next commit against devel/phpunit6 was 447659 (201708092330.v79NU35e060658@repo.freebsd.org).
Let’s look into that log file and … see what I found:
$ cd ../../2017_08/2017_08_09 $ grep -l 201708092330.v79NU35e060658@repo.freebsd.org * 2017.08.09.23.30.09.9876.txt.loading 2017.08.09.23.30.09.9876.txt.raw 2017.08.09.23.30.09.9876.txt.xml
From in 2017.08.09.23.30.09.9876.txt.loading I found:
# # # # Resurrecting deleted ports # # # # found a deleted port: port='phpunit6', port_id='41762', element_id='789692' now looking for files which were modified... inspecting: 'Modify', '/ports/head/devel/phpunit6/Makefile', '447659', '', 'ports', 'devel/phpunit6/Makefile' inspecting: 'Modify', '/ports/head/devel/phpunit6/distinfo', '447659', '', 'ports', 'devel/phpunit6/distinfo' finished looking through the files # # # # Finished resurrecting deleted ports # # # #
Huh. It’s trying to resurrect again.
I looked at the most recent commit (456937) and found:
# # # # Resurrecting deleted ports # # # # found a deleted port: port='phpunit6', port_id='41762', element_id='789692' now looking for files which were modified... inspecting: 'Modify', '/ports/head/devel/phpunit6/Makefile', '456937', '', 'ports', 'devel/phpunit6/Makefile' inspecting: 'Modify', '/ports/head/devel/phpunit6/distinfo', '456937', '', 'ports', 'devel/phpunit6/distinfo' finished looking through the files # # # # Finished resurrecting deleted ports # # # #
I will bet every single commit in between is trying to resurrect and is failing.
Let’s find out why.
Resurrection
When looking at the backend code, I concluded that this condition was never true:
if ($category_name eq $port->{category} && $port->{name} eq $port_name) {
I added more debugging statements to the code and reran those commits in the same order:
$ perl load_xml_into_db.pl /usr/FreshPorts/freshports.org/msgs/FreeBSD/archive/2017_03/2017_03_30/2017.03.30.15.03.21.25140.txt.xml -O > ~/tmp/creating.1 $ perl load_xml_into_db.pl /usr/FreshPorts/freshports.org/msgs/FreeBSD/archive/2017_03/2017_03_30/2017.03.30.15.10.13.14518.txt.xml -O > ~/tmp/removing.1
After running the first command, the port was no longer in a deleted state. That makes sense.
The second command, which removed the port, left the port in a deleted state. That makes sense too.
However, examination of the the removal log revealed the cause of the problem:
# # # # Resurrecting deleted ports # # # # at the top of loop with $portname='devel/phpunit6' found a deleted port: category='devel', port='phpunit6', port_id='41762', element_id='789692' now looking for files which were modified... inspecting: 'Remove', '/ports/head/devel/phpunit6/', '437301', '', 'ports', 'devel/phpunit6/' which splits to: $subtree='', $category_name='ports', $port_name='head', and $extra='devel/phpunit6/' finished looking through the files # # # # Finished resurrecting deleted ports # # # #
The problem is the split. It is not so much the split as the fact that pathnames changed and much work was done on branches.
Instead of having separate calls to split, I should have a function which does this instead.
As you can see on line 7, the values for $category_name and $port_name are wrong. The split caused this.
You might be thinking: yeah, but the code should not resurrect this port when the commit is deleting. Yes, that is correct. However, the code first wants to detect that the file in questions belongs to a deleted port. This is the criteria for resurrection: an action occurs on a deleted port. Once this situation is detected, the code looks at the action being performed on that file. It the action is an Add or a Modify, only then will the port will be resurrected. If the action is a Delete, the resurrection will not occur.
What code has this issue
I starting grepping for split. I have included the output which relates directly to pathnames.
branches.pm: my ($emptyLeadingSlash, $subtree, $branch, $category, $port) = split/\//,$pathname, 5; observer_commits.pm: my ($subtree, $category_name, $port_name, $extra) = split/\//,$filename, 4; verifyport.pm: ($emptyLeadingSlash, $subtree, $branch, $category_name, $port_name, $extra) = split/\//,$filename, 6; verifyport.pm: ($emptyLeadingSlash, $subtree, $branches, $branch, $category_name, $port_name, $extra) = split/\//,$filename, 7; verifyport.pm: ($subtree, $category_name, $port_name, $extra) = split/\//,$filename, 4; verifyport.pm: my ($subtree, $category_name, $port_name, $extra) = split/\//,$filename, 4;
Yes, this is not idea. I should create a new dedicated function.
The code in branches.pm appears to be correct, but that split is within the GetBranchFromPathName() function. The goal there is not to determine port or category, but branch. It is doing the right thing, and is outside scope for a pathname function.
My immediate thought is the observer_commits.pm split may be related to issue #56 and I will leave that for another day.
That leaves only the verifyport.pm code.
Code changes
Initially, I thought that creating a perl function which returns multiple parameters was beyond my skill set, but after sleeping upon it, I created a function which returned a hash. In the interim, I fixed the splits in verifyport.pm to be correct, and later converted them to a function call.
This seems to be the correct approach and includes the first two splits shown above:
# define them first
my ($emptyLeadingSlash, $subtree, $branches, $branch, $category_name, $port_name, $extra);
# depending on which branch we are one, we need to split this path differently
if ($CommitBranch eq $FreshPorts::Constants::HEAD)
{
($emptyLeadingSlash, $subtree, $branch, $category_name, $port_name, $extra) = split/\//,$filename, 6;
}
else
{
($emptyLeadingSlash, $subtree, $branches, $branch, $category_name, $port_name, $extra) = split/\//,$filename, 7;
}
The above them became the basis for the new function.
The second bit of code is definitely wrong.
print "\n\nThat message is all done under Commit ID = '$commit_log_id'\n";
print "the size of \@Files is ", scalar(@{$Files}), "\n";
#
# in this loop assign a value to needs_refresh for each port
#
foreach $value (@{$Files}) {
($action, $filename, $revision, $commit_log_element_id, $element_id) = @$value;
($subtree, $category_name, $port_name, $extra) = split/\//,$filename, 4;
print "FILE ==STARTING _CompileListOfPorts: $action, $filename, $revision, $subtree, $category_name, ";
if (defined($port_name)) {
print "$port_name, ";
}
if (defined($extra)) {
print "$extra, ";
}
print "$commit_log_element_id\n";
Sample output from this code (for revision = 458079 and message_id = 201801042012.w04KCc56056293@repo.freebsd.org) is:
That message is all done under Commit ID = '687179' the size of @Files is 3 FILE ==: Add, /ports/head/databases/rubygem-mysql/files/, 458079, , ports, head, databases/rubygem-mysql/files/, 3407977 FILE ==: Add, /ports/head/databases/rubygem-mysql/files/patch-ext-mysql_api-mysql.c, 458079, , ports, head, databases/rubygem-mysql/files/patch-ext-mysql_api-mysql.c, 3407978 FILE ==: Modify, /ports/head/databases/rubygem-mysql/Makefile, 458079, , ports, head, databases/rubygem-mysql/Makefile, 3407979
On every line, you can see an empty value for $subtree, the $category_name is always ‘ports’, and the $port_name is always ‘head’. Yeah, that needs to be fixed too.
Testing the changes
The changes were tested by running the Create commit, then the Add commit. The incorrect situation was now restored with the port in a Deleted state.
Then I ran a later commit (23 Apr 2017 09:04:40, revision 439210 – 201704230904.v3N94eZs084807@repo.freebsd.org) in the series (
# # # # Resurrecting deleted ports # # # # at the top of loop with $portname='devel/phpunit6' found a deleted port: category='devel', port='phpunit6', port_id='41762', element_id='789692' now looking for files which were modified... inspecting: 'Modify', '/ports/head/devel/phpunit6/Makefile', '439210', 'ports', 'devel', 'Makefile' which splits to: $subtree='ports', $category_name='devel', $port_name='phpunit6', and $extra='Makefile' ...found a file from that port ...hmmm, we are modifying a file for a port which is deleted... ........ I will resurrect that port for you Port devel/phpunit6 needs to be Resurrected ........ done! inspecting: 'Modify', '/ports/head/devel/phpunit6/distinfo', '439210', 'ports', 'devel', 'distinfo' which splits to: $subtree='ports', $category_name='devel', $port_name='phpunit6', and $extra='distinfo' ...found a file from that port ...hmmm, we are modifying a file for a port which is deleted... ........ I will resurrect that port for you Port devel/phpunit6 needs to be Resurrected ........ done! finished looking through the files # # # # Finished resurrecting deleted ports # # # #
As you can see, it has correctly decided to resurrect that deleted port.
Should another Remove/Create pair of commits be processed in reverse order, the next commit will automatically correct the situation.
PORTREVISION issues
Why are all the commits listed as PORTREVISION = 6.0.11?
I reviewed the log for the However, deep in the log for the 439210 commit. I found:
This port is deleted: not refreshing. This port is deleted: not saving.
I have to fix that. None of the changes are being saved. The ports tree has been svn up’d correctly, but the values are not being extracted and placed into the database.
That problem would explain why all the subsequent commits have the same revision.
The fix involves altering the local copy of the port as the database version is updated:
if ($category_name eq $port->{category} && $port->{name} eq $port_name) {
print " ...found a file from that port\n";
if ($action eq $FreshPorts::Constants::ADD || $action eq $FreshPorts::Constants::MODIFY) {
print " ...hmmm, we are modifying a file for a port which is deleted...";
print " ........ I will resurrect that port for you\n";
FreshPorts::Utilities::ReportError('notice', "Port $category_name/$port_name needs to be Resurrected", 0);
$element->{id} = $port->{element_id};
$element->{status} = $FreshPorts::Element::Active;
$element->update_status();
# this will ensure that the port is updated at the end of the commit processing.
# deleted ports are not update.
$port->{status} = $FreshPorts::Element::Active;
print " ........ done!\n";
}
}
Lines 11-14 fix that issue. Each port has a corresponding entry in the element table. When the element status is updated, the port status is automatically updated. These lines reflect that action.
Why not process in order?
To process commits in order is easy.
Watch svn for any increments in revision number, pull that revision, process it.
It sounds trivial, but it’s a matter of coding.
The changes include:
- Create a process to monitor the repo
- Alter the XML file creation to source data only from the commit repo. This information is currently pulled from the commit email, which contains considerably more information.
Got patches?
Additional work to be completed
Following from just fixing this bug, there is additional work arising out of this.
Other ports
I have no doubt that this bug has affected other ports which will be incorrectly marked as being deleted. It may be relatively easy to compare the list of ports against INDEX to verify which ports have the incorrect status.
Other commits
Every commit after such a remove such as this one must be rerun. This is the fallout from the PORTREVISION issues mentioned above.
