Hi Everyone,
Further to my email posted on on the 13th of December, I've conducted some
futher tests and think that there is a problem in the recovery process when
an entry in the recovery log has some SQL parameters defined in the
"sql_param" column.
My setup is summarised as follows:
Sequoia 2.10.2
Postgres 8.1.2 (as primary, backup and recovery databases, "db_primary",
"db_backup" and "recovery" respectively)
Hibernate 3.1.3 (ORM tool used by clients to persist Java objects into the
virtual DB)
After performing a backup "testbackup" (via the console), I get my client to
write some data into the virtual DB using Hibernate (see recover log ids 429
- 432). I also use SQL explorer to connect to the virtual DB and manually
add some data (see recover log ids 447 - 450).
Here is part of the recovery log showing this:
log_id | vlogin |
sql
|
sql_param | auto_conn_tran | transaction_id |
request_id | exec_status | exec_time | update_count
429 | user | {call nextval('hibernate_sequence')}
|
| T | 365 | 381 | S | 21 |
0
430 | user | insert into tablea (componentName, timestamp, id) values (?,
?, ?)
|
<!%S|abc|!%><!%L|1166491718006|!%><!%L|17|!%> | T |
365 | 382 | S | 11 | 1
431 | user | commit
|
| T | 365 | 0 | S | 0 |
0
432 | user | commit
|
| T | 366 | 0 | S | 0 |
0
.
.
.
447 | user | insert into tablea values(102, 'abc', 102)
|
| A | 0 | 394 | S | 54 |
1
448 | user | insert into tablea values(101, 'abc', 101)
|
| A | 0 | 395 | S | 55 |
1
449 | user | insert into tablea values(100, 'abc', 100)
|
| A | 0 | 396 | S | 45 |
1
450 | user | {call nextval('hibernate_sequence')}
|
| A | 0 | 398 | S | 62 |
0
I then go to restore the backends from my backup through the console. I do
the following:
1. disable *
2. restore backend db_primary testbackup
3. restore backend db_backup testbackup
4. force checkpoint db_primary checkpoint_corresponding_to_the_backup (as
reported in "show dumps")
5. force checkpoint db_backup checkpoint_corresponding_to_the_backup (as
reported in "show dumps")
6. enable *
The result is:
=============
i) I don't see any of the operations from log_id's 429 - 432 written to my
backends
ii) I DO see the operations from log_id's 447 - 450 (inclusive) written to
my backends
Because the "hibernate_sequence" table sequence number is updated (by 1) as
a result of log_id 450 (I've confirmed this) then I believe that the
recovery process is having some sort of problem with log_id 430;
430 | user | insert into tablea (componentName, timestamp, id) values (?,
?, ?)
|
<!%S|abc|!%><!%L|1166491718006|!%><!%L|17|!%> | T |
That is, when encountering the <!%S|abc|!%><!%L|1166491718006|!%><!%L|17|!%>
in the "sql_param" column, some problem is occurring.
I do have my log4j logging level set to DEBUG for all components, but no
errors are reported.
Can anyone confirm or explain this behaviour?
Many thanks,
Ken
_______________________________________________
Sequoia mailing list
[email protected]
https://forge.continuent.org/mailman/listinfo/sequoia
