This must be something very simple, but I can't seem to be able to figure it out. Must be Friday after a busy week...


I did a rollforward with UTC and local time. The difference between UTC and local time is 4 hrs on my server:


$ db2 "values current timezone"

1
--------
-40000.


$ date; date -u
Fri Sep 10 18:13:10 EDT 2010
Fri Sep 10 22:13:10 GMT 2010


-- Rollforward using UTC

$ db2 rollforward db test to 2010-09-10-21.58.56.000000 and stop

Rollforward Status

Input database alias = test
Number of nodes have returned status = 1

Node number = 0
Rollforward status = not pending
Next log file to be read =
Log files processed = S0000000.LOG - S0000000.LOG
Last committed transaction = 2010-09-10-21.58.56.000000 UTC

DB20000I The ROLLFORWARD command completed successfully.


-- Rollforward using local time

$ db2 rollforward db test to 2010-09-10-17.58.56.000000 using local time and stop

Rollforward Status

Input database alias = test
Number of nodes have returned status = 1

Node number = 0
Rollforward status = not pending
Next log file to be read =
Log files processed = S0000000.LOG - S0000000.LOG
Last committed transaction = 2010-09-10-17.58.56.000000 Local

DB20000I The ROLLFORWARD command completed successfully.


Everything looks good to me.



But on the customer's system:

$ db2 rollforward db TEST to 2010-09-09-11.00.00.000000 and stop (7am local time)

Rollforward Status

Input database alias = TEST
Number of nodes have returned status = 1

Node number = 0
Rollforward status = not pending
Next log file to be read =
Log files processed = S0018613.LOG - S0018620.LOG
Last committed transaction = 2010-09-09-10.59.55.000000 UTC

DB20000I The ROLLFORWARD command completed successfully.




$ db2 rollforward db TEST to 2010-09-09-11.00.00.000000 USING LOCAL TIME and stop

Rollforward Status

Input database alias = TEST
Number of nodes have returned status = 1

Node number = 0
Rollforward status = not pending
Next log file to be read =
Log files processed = S0018613.LOG - S0018621.LOG
Last committed transaction = 2010-09-09-06.59.55.000000 Local

DB20000I The ROLLFORWARD command completed successfully.


The difference between UTC and local time is also 4hrs on their system as can be seen from the list history output:

Comment: 20100909204754GMT
Start Time: 20100909164448
End Time: 20100909164754


TZ env variable is setup the same on both servers.


DB2 processed an additional log file (normal). What I'm not sure about is why the "Last committed transaction" is displayed as "2010-09-09-06.59.55.000000 Local" and not "2010-09-09-10.59.55.000000 Local"


Any idea?

And there were committed transactions after 6:59am local time.

How do you know that?

I saw some table drops taking place after 7am in the history file. I'd have checked the transaction logs if I had them.

But I think I know why db2 didn't process the logs up to the specified time and stopped at 6:59. I'm just not thinking straight today... This was a second restore/rollforward attempt to a PIT (first using UTC and second using local) so db2 created a new log chain after the first one. I'll think about this again in the morning.

I'll add some info regarding this situation here. Maybe someone, including myself, will run into a similar situation in the future.