On 12/16/12 15:05, Allan McRae wrote:

On 13/12/12 23:19, Olivier Brunel wrote:

...

The "starting sysupgrade" message was logged quite soon, making it be added even when nothing was actually done, because there was nothing to do, the user didn't confirm, or asked to only download packages.

The log message is now added only when (before) committing the transaction. And we also log a message at the end (in case of success or failure).

Signed-off-by: Olivier Brunel --- src/pacman/sync.c | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/src/pacman/sync.c b/src/pacman/sync.c index f8fce7f..77fd573 100644 --- a/src/pacman/sync.c +++ b/src/pacman/sync.c @@ -793,7 +793,6 @@ static int sync_trans(alpm_list_t *targets)

if(config->op_s_upgrade) { printf(_(":: Starting full system upgrade...\n")); - alpm_logaction(config->handle, "starting full system upgrade\n");

I really do not like that moving this prints effectively the same message at two different times. Also, the line below really is the start of the system upgrade.

By two different times, you mean to the user and in the log? In such a case, this first message could be something else, e.g. "preparing full system upgrade" or something to that effect, and moving the "starting" along with the log one. What I don't like with the current situation, is that the message (in the log) says "starting sysupgrade" while it might not really be the case, because of a conflict, user didn't confirmed, or there was nothing to do. That's why I wanted the message to do logged before the operation was confirmed, and the sysupgrade will effectively be attempted/started.

...

if(alpm_sync_sysupgrade(config->handle, config->op_s_upgrade >= 2) == -1) { pm_printf(ALPM_LOG_ERROR, "%s\n", alpm_strerror(alpm_errno(config->handle))); trans_release(); @@ -879,6 +878,9 @@ int sync_prepare_execute(void) goto cleanup; }

+ if(config->op_s_upgrade) { + alpm_logaction(config->handle, "starting full system upgrade\n"); + } if(alpm_trans_commit(config->handle, &data) == -1) { alpm_errno_t err = alpm_errno(config->handle); pm_printf(ALPM_LOG_ERROR, _("failed to commit transaction (%s)\n"), @@ -911,11 +913,16 @@ int sync_prepare_execute(void) default: break; } + alpm_logaction(config->handle, "failed to commit transaction (%s)\n", + alpm_strerror(err));

Why only this error? There are other just as valid error conditions to log.

I wanted to log something after the "start" message, to either say it was successful, or failed. Other errors occur before the start message is logged, that's why they're not logged.

...

/* TODO: stderr? */ printf(_("Errors occurred, no packages were upgraded.\n")); retval = 1; goto cleanup; } + alpm_logaction(config->handle, (config->op_s_upgrade) + ? "full system upgrade completed\n" + : "installation completed\n");

Just realized, that this probably should account for another case: "download completed"

...

/* Step 4: release transaction resources */ cleanup:

On 12/16/12 15:38, Allan McRae wrote:

On 17/12/12 00:25, jjacky wrote:

...

On 12/16/12 15:05, Allan McRae wrote:

...

On 13/12/12 23:19, Olivier Brunel wrote:

...

The "starting sysupgrade" message was logged quite soon, making it be added even when nothing was actually done, because there was nothing to do, the user didn't confirm, or asked to only download packages.

The log message is now added only when (before) committing the transaction. And we also log a message at the end (in case of success or failure).

Signed-off-by: Olivier Brunel --- src/pacman/sync.c | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/src/pacman/sync.c b/src/pacman/sync.c index f8fce7f..77fd573 100644 --- a/src/pacman/sync.c +++ b/src/pacman/sync.c @@ -793,7 +793,6 @@ static int sync_trans(alpm_list_t *targets)

if(config->op_s_upgrade) { printf(_(":: Starting full system upgrade...\n")); - alpm_logaction(config->handle, "starting full system upgrade\n");

I really do not like that moving this prints effectively the same message at two different times. Also, the line below really is the start of the system upgrade.

By two different times, you mean to the user and in the log? In such a case, this first message could be something else, e.g. "preparing full system upgrade" or something to that effect, and moving the "starting" along with the log one.

What I don't like with the current situation, is that the message (in the log) says "starting sysupgrade" while it might not really be the case, because of a conflict, user didn't confirmed, or there was nothing to do. That's why I wanted the message to do logged before the operation was confirmed, and the sysupgrade will effectively be attempted/started.

This is where I completely disagree. I see the upgrade operation starting when pacman checks what is currently installed and whether there is a new version of it.

If there is a conflict in the packages, what failed? The system upgrade... so the system upgrade must have started...

Right. Well, it could be said/seen differently: as far as pacman goes, there's really two steps: - preparing the transaction - committing the transaction You say the sysupgrade starts with step 1, which makes sense of course, but it could be argued that even after step 1 is completed, it hasn't really started. That's why then, between those two steps, pacman will ask the user whether to proceed or not. Or just stops if there's nothing to actually do. Or, in other words, the system upgrade might start with step one, but the installation(*) does with step 2. Would you agreed with that? (*) Noting it could actually be a download-only operation. If so, I feel what should be logged is when the installation starts (and when it's completed/failed) and not when the upgrade (i.e. including the preparation/step 1) does. This is mostly because I don't see the point of logging "starting sysupgrade" and then nothing, since we don't know why there's nothing. And e.g. logging "starting / nothing to do" seems useless to me. Maybe the "starting sysupgrade" message could stay as/where it is, but not be logged, and the log message would be before the alpm_trans_commit call, but say "starting installation" instead ? (It could also be shown to the user as well, if that makes things clearer?)

...

...

...

if(alpm_sync_sysupgrade(config->handle, config->op_s_upgrade >= 2) == -1) { pm_printf(ALPM_LOG_ERROR, "%s\n", alpm_strerror(alpm_errno(config->handle))); trans_release(); @@ -879,6 +878,9 @@ int sync_prepare_execute(void) goto cleanup; }

+ if(config->op_s_upgrade) { + alpm_logaction(config->handle, "starting full system upgrade\n"); + } if(alpm_trans_commit(config->handle, &data) == -1) { alpm_errno_t err = alpm_errno(config->handle); pm_printf(ALPM_LOG_ERROR, _("failed to commit transaction (%s)\n"), @@ -911,11 +913,16 @@ int sync_prepare_execute(void) default: break; } + alpm_logaction(config->handle, "failed to commit transaction (%s)\n", + alpm_strerror(err));

Why only this error? There are other just as valid error conditions to log.

I wanted to log something after the "start" message, to either say it was successful, or failed. Other errors occur before the start message is logged, that's why they're not logged.

...

...

/* TODO: stderr? */ printf(_("Errors occurred, no packages were upgraded.\n")); retval = 1; goto cleanup; } + alpm_logaction(config->handle, (config->op_s_upgrade) + ? "full system upgrade completed\n" + : "installation completed\n");

Just realized, that this probably should account for another case: "download completed"

...

...

/* Step 4: release transaction resources */ cleanup:

On 12/16/12 16:02, Allan McRae wrote:

On 17/12/12 00:52, jjacky wrote:

...

On 12/16/12 15:38, Allan McRae wrote:

...

On 17/12/12 00:25, jjacky wrote:

...

On 12/16/12 15:05, Allan McRae wrote:

...

On 13/12/12 23:19, Olivier Brunel wrote:

...

The "starting sysupgrade" message was logged quite soon, making it be added even when nothing was actually done, because there was nothing to do, the user didn't confirm, or asked to only download packages.

The log message is now added only when (before) committing the transaction. And we also log a message at the end (in case of success or failure).

Signed-off-by: Olivier Brunel --- src/pacman/sync.c | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/src/pacman/sync.c b/src/pacman/sync.c index f8fce7f..77fd573 100644 --- a/src/pacman/sync.c +++ b/src/pacman/sync.c @@ -793,7 +793,6 @@ static int sync_trans(alpm_list_t *targets)

if(config->op_s_upgrade) { printf(_(":: Starting full system upgrade...\n")); - alpm_logaction(config->handle, "starting full system upgrade\n");

I really do not like that moving this prints effectively the same message at two different times. Also, the line below really is the start of the system upgrade.

By two different times, you mean to the user and in the log? In such a case, this first message could be something else, e.g. "preparing full system upgrade" or something to that effect, and moving the "starting" along with the log one.

What I don't like with the current situation, is that the message (in the log) says "starting sysupgrade" while it might not really be the case, because of a conflict, user didn't confirmed, or there was nothing to do. That's why I wanted the message to do logged before the operation was confirmed, and the sysupgrade will effectively be attempted/started.

This is where I completely disagree. I see the upgrade operation starting when pacman checks what is currently installed and whether there is a new version of it.

If there is a conflict in the packages, what failed? The system upgrade... so the system upgrade must have started...

Right. Well, it could be said/seen differently: as far as pacman goes, there's really two steps: - preparing the transaction - committing the transaction

You say the sysupgrade starts with step 1, which makes sense of course, but it could be argued that even after step 1 is completed, it hasn't really started. That's why then, between those two steps, pacman will ask the user whether to proceed or not. Or just stops if there's nothing to actually do.

Or, in other words, the system upgrade might start with step one, but the installation(*) does with step 2. Would you agreed with that?

(*) Noting it could actually be a download-only operation.

If so, I feel what should be logged is when the installation starts (and when it's completed/failed) and not when the upgrade (i.e. including the preparation/step 1) does.

This is mostly because I don't see the point of logging "starting sysupgrade" and then nothing, since we don't know why there's nothing. And e.g. logging "starting / nothing to do" seems useless to me.

Maybe the "starting sysupgrade" message could stay as/where it is, but not be logged, and the log message would be before the alpm_trans_commit call, but say "starting installation" instead ? (It could also be shown to the user as well, if that makes things clearer?)

Let take a step back...

The question that needs to be answered is "What is the benefit of moving that message?"

It would be moved right before updating packages. But ever package update is logged, so what is the gain?

Well, as I said, I'd like to avoid a log with "starting sysupgrade" and then nothing, not knowing why nothing happened (user not confirming, nothing to be done, file system conflict, etc). Moving it means in case of user not confirming or nothing to be done, nothing gets logged. Adding a completed/failed afterwards also makes things clearer, ensuring everything went fine (well, or not/failed but we know).

Allan

On 12/16/12 14:50, Allan McRae wrote:

On 13/12/12 23:19, Olivier Brunel wrote:

...

Signed-off-by: Olivier Brunel --- This simply adds information about what was actually done, I left the "synchronizing" message in case it's used by external tools (e.g. pacmatic).

Do we need output in all three cases?

I am just thinking about bloat in the log file. A quick look in my pacman log file indicates this would add another 60% lines to the log. As this log should not be rotated, we do not want it too bloated.

Would it be better to just log when it is updated or failed, and log nothing when nothing is done?

Opinions?

I originally only logged when a db was updated, I feel that's really the one that matters. Removing the up-to-date message is probably best yes.

...

src/pacman/sync.c | 6 ++++++ 1 file changed, 6 insertions(+)

diff --git a/src/pacman/sync.c b/src/pacman/sync.c index 532a667..f8fce7f 100644 --- a/src/pacman/sync.c +++ b/src/pacman/sync.c @@ -331,12 +331,18 @@ static int sync_synctree(int level, alpm_list_t *syncs)

int ret = alpm_db_update((level < 2 ? 0 : 1), db); if(ret < 0) { + alpm_logaction(config->handle, "failed to update %s (%s)\n", + alpm_db_get_name(db), alpm_strerror(alpm_errno(config->handle))); pm_printf(ALPM_LOG_ERROR, _("failed to update %s (%s)\n"), alpm_db_get_name(db), alpm_strerror(alpm_errno(config->handle))); } else if(ret == 1) { + alpm_logaction(config->handle, "%s is up to date\n", + alpm_db_get_name(db)); printf(_(" %s is up to date\n"), alpm_db_get_name(db)); success++; } else { + alpm_logaction(config->handle, "synchronized %s\n", + alpm_db_get_name(db)); success++; } }