Logging: Useless log file on failed activate during upgrade

[raimue (Rainer Müller)]

In a special case the logging procedure writes a useless log file. Here a port has to be activated in order to build a dependent port. But the activation fails and results in a useless, self-referencing log file.

The following example is a demonstration of the bug in the wild:

$ port -v outdated py26-docutils 
The following installed ports are outdated:
py26-docutils                  0.5_1 < 0.6_0             
$ port -v installed py26-roman
The following ports are currently installed:
  py26-roman @1.4.0_0
$ sudo port upgrade py26-docutils
--->  Computing dependencies for py26-docutils
--->  Activating py26-roman @1.4.0_0
Log for py26-roman is at: /opt/local/var/macports/logs/_Users_raim_src_macports_trunk_dports_python_py26-roman/main.log
Error: The following dependencies failed to build: py26-roman
Error: Unable to upgrade port: 1
To report a bug, see <http://guide.macports.org/#project.tickets>

The resulting log file:

$ port log py26-roman
--->  Activating py26-roman @1.4.0_0
Log for py26-roman is at: /opt/local/var/macports/logs/_Users_raim_src_macports_trunk_dports_python_py26-roman/main.log

$ cat /opt/local/var/macports/logs/_Users_raim_src_macports_trunk_dports_python_py26-roman/main.log
version:1
:msg:main --->  Activating py26-roman @1.4.0_0
:msg:main Log for py26-roman is at: /opt/local/var/macports/logs/_Users_raim_src_macports_trunk_dports_python_py26-roman/main.log

[raimue (Rainer Müller)]

Here is additional debug output:

$ sudo port -d upgrade py26-docutils

...

--->  Computing dependencies for py26-docutils
DEBUG: Searching for dependency: py26-roman
DEBUG: Didn't find receipt, going to depspec regex for: py26-roman
DEBUG: Changing to port directory: /Users/raim/src/macports/trunk/dports/python/py26-roman
DEBUG: OS darwin/10.2.0 (Mac OS X 10.6) arch i386
DEBUG: org.macports.load registered provides 'load', a pre-existing procedure. Target override will not be provided
DEBUG: org.macports.unload registered provides 'unload', a pre-existing procedure. Target override will not be provided
DEBUG: org.macports.distfiles registered provides 'distfiles', a pre-existing procedure. Target override will not be provided
DEBUG: Using group file /Users/raim/src/macports/trunk/dports/_resources/port1.0/group/python26-1.0.tcl
DEBUG: not using configure, so not adding the default universal variant
DEBUG: Requested variant darwin is not provided by port py26-roman.
DEBUG: Requested variant i386 is not provided by port py26-roman.
DEBUG: Requested variant macosx is not provided by port py26-roman.
DEBUG: Requested variant bash_completion is not provided by port py26-roman.
DEBUG: Searching for dependency: py26-setuptools
DEBUG: Found Dependency: receipt exists for py26-setuptools
DEBUG: Starting logging for py26-roman
--->  Activating py26-roman @1.4.0_0
Log for py26-roman is at: /opt/local/var/macports/logs/_Users_raim_src_macports_trunk_dports_python_py26-roman/main.log
Error: The following dependencies failed to build: py26-roman
DEBUG: invalid command name "::ui_init"
    while executing
"::ui_init error Error: stderr debuglog {The following dependencies failed to build: py26-roman}"
    ("eval" body line 1)
    invoked from within
"eval ::ui_init $priority $prefix $channels($priority) $args"
    ("uplevel" body line 2)
    invoked from within
"uplevel 1 $body"
Error: Unable to upgrade port: 1
To report a bug, see <http://guide.macports.org/#project.tickets>

[jmroot (Joshua Root)]

Probably ending up in the dependent's log due to a missing push_log?

[jmroot (Joshua Root)]

Was this fixed by r64007?

[raimue (Rainer Müller)]

I reproduced the issue with a new port foo which has a dependency on less:

sudo port deactivate less
sudo touch /opt/local/bin/less

$ sudo port install foo
--->  Computing dependencies for foo..
--->  Activating less @436_0
Error: activating less @436_0 failed: Image error: /opt/local/bin/less already exists and does not belong to a registered port.  Unable to activate port less. Use 'port -f activate less' to force the activation.
Log for less is at: /opt/local/var/macports/logs/_Users_raim_src_macports_trunk_dports_textproc_less/main.log
Error: The following dependencies failed to build: less
Error: Status 1 encountered during processing.
To report a bug, see <http://guide.macports.org/#project.tickets>

$ port log less
DEBUG: Attempting ln -sf /opt/local/var/macports/build/_Users_raim_src_macports_trunk_dports_textproc_less/work /Users/raim/src/macports/trunk/dports/textproc/less/work
--->  Activating less @436_0
DEBUG: Image error: /opt/local/bin/less already exists and does not belong to a registered port.  Unable to activate port less. Use 'port -f activate less' to force the activation.
Error: activating less @436_0 failed: Image error: /opt/local/bin/less already exists and does not belong to a registered port.  Unable to activate port less. Use 'port -f activate less' to force the activation.
Log for less is at: /opt/local/var/macports/logs/_Users_raim_src_macports_trunk_dports_textproc_less/main.log

$ cat /opt/local/var/macports/logs/_Users_raim_src_macports_trunk_dports_textproc_less/main.log
version:1
:debug:main Attempting ln -sf /opt/local/var/macports/build/_Users_raim_src_macports_trunk_dports_textproc_less/work /Users/raim/src/macports/trunk/dports/textproc/less/work
:msg:main --->  Activating less @436_0
:debug:main Image error: /opt/local/bin/less already exists and does not belong to a registered port.  Unable to activate port less. Use 'port -f activate less' to force the activation.
    while executing
"_activate_contents $name $imagefiles $imagedir"
    (procedure "portimage::activate" line 105)
    invoked from within
"registry_activate $name ${version}_${revision}${portvariants} [array get user_options]"
:error:main activating less @436_0 failed: Image error: /opt/local/bin/less already exists and does not belong to a registered port.  Unable to activate port less. Use 'port -f activate less' to force the activation.
:msg:main Log for less is at: /opt/local/var/macports/logs/_Users_raim_src_macports_trunk_dports_textproc_less/main.log

Looks much better now.

But is the "Log for $port is at:" message supposed to be in the log file?