DBRemote - Strange Log File Processing

[former_SQLA_member1694989]

I've run into a situation that I have never seen before. Whenever DB remote starts, it starts processing logs from a really old offset. It starts processing the first log with an offset of 02671972308733. The lowest confirm_sent value in sysremoteusers is 2721805774848. DBRemote spends about 2 hours going through the log files from 5/5 to 5/28, and doesn't create a single message until it gets to the log files from 5/28. Does anybody know why it would process through all of those old log files when it doesn't need to? If it did it quickly, maybe I could live with it, but it takes 2 hours every time, creating a long delay when it needs to send messages out. In checking through the old dbrmeote.log files, it looks like this has only been occurring for roughly the last 3 weeks, but I can't see anything that's changed in that time frame on the server.

The Delete_old_logs option is set to Delay.

I. 2020-05-28 14:46:57. Scanning logs starting at offset 02755084370055
I. 2020-05-28 14:46:57. Transaction log "D:/HomeWorks/Prod/btihw.log" starts at offset 02755140297562
I. 2020-05-28 14:46:57. Processing transaction logs from directory "d:\\Homeworks\\Prod"
I. 2020-05-28 14:46:58. Transaction log "d:\\Homeworks\\Prod\\200508BA.LOG" starts at offset 02671972308733
I. 2020-05-28 14:46:58. Processing transactions from transaction log "d:\\Homeworks\\Prod\\200508BA.LOG"
I. 2020-05-28 14:46:58. Scanning logs starting at offset 02672016196979
I. 2020-05-28 14:47:04. Transaction log ends at offset 02672021652236
I. 2020-05-28 14:47:04. Transaction log "d:\\Homeworks\\Prod\\200508BB.LOG" starts at offset 02672021652236
I. 2020-05-28 14:47:04. Processing transactions from transaction log "d:\\Homeworks\\Prod\\200508BB.LOG"
I. 2020-05-28 14:47:06. Transaction log ends at offset 02672032365473

[regdomaratzki]

What version of dbremote are you using?

If the minimum confirm_sent value in the SYSREMOTEUSER table is 2721805774848, that is the offset that it will need to begin scanning from. I suspect that there is transaction that commits after that offset that starts in the transaction log that begins at offset 2671972308733, which will force dbremote to scan back to that transaction log, in case that transaction that commits after 2721805774848 contains operations that need to be sent.

Is there only a single remote user with a confirm_sent value that is quite old? Can you look in the dbremote log and check on the history of message being picked up and sent to that remote user in the last three weeks? Does the resend count on messages being sent to the remote user continue to increase?

Reg

[former_SQLA_member1694989]

Version - 16.0.0.2213

There is one user at 2,721B, the next user is at 2,738B, then there are a group of 10 or so users at 2,746B.

My confusion is if there is not a resend request for that first user, why is dbremote even caring about those old log files.

For that particular remote, the last time the resend count increased was on 4/24. I can see many good syncs from the month of May where the confirm_sent is progressing each time. At the beginning of May, the confirm_sent is 2,654B and moves up 2,717B on the last sync on 5/19. We keep a history of the sysremoteusers table from the remote side, so I can see we are getting good syncs from that history table.

And Reg, I haven't see been to a Sybase conference since the pre-SAP days, but it's nice to talk with you again.

[former_SQLA_member1694989]

One thing I forgot to mention earlier, this behavior from dbremote happens every time dbremote switches from receiving to sending. In the dbremote log file, you can see that it does that every time.

Reg - The behavior that you are describing is what I would expect to see on a resend request. DBRemote loads the log file(s) that it needs to recreate old messages and it takes time to go through all the old log files. It's very, very surprising to see this behavior every time the dbremote service creates messages for any remote.

[regdomaratzki]

I was asking about the resend count increasing because I thought it was possible that every time dbremote ran on the consolidated, it would get a resend request from the same remote user and be forced to scan the log files again to satisfy the resend request.

I don't know that the forum is the best place to address this issue. What I'd really like to see to better understand the issue is :

1. A snapshot of the SYSREMOTEUSERS view at time X.
2. The output from dbremote (no -v needed) when it runs at time X+1.
3. A snapshot of the SYSREMOTEUSERS view at time X+2.
4. The output from dbremote (no -v needed) when it runs at time X+3.
5. A snapshot of the SYSREMOTEUSERS view at time X+4.
6. The offsets.txt file generated from running the following command in a command prompt in the directory where renamed transaction log files reside : for %i in (*.log) do dblog %i >> offsets.txt

Would you be able to gather this information and make it available?

I should point out that gathering this information will likely just result in more questions, not a solution.

Reg

[former_SQLA_member1694989]

Thanks Reg. I will work on that today.

[Baron]

DBREMOTE first reads and applies the incoming messages and then processes its transaction log files (in order to generate messages).

I would try in such a case to start DBREMOTE without incoming messages (i.e. after purging the messages from the folders of select "address" from sysremoteusers

Or maybe even starting DBREMOTE with -s option (send only).

As next step, I would reset the remotes gradually (in a test system).

REMOTE RESET user_of_2721B;

DBREMOTE.exe

REMOTE RESET user_of_2738B;

DBREMOTE.exe

...

...

[former_SQLA_member1694989]

Oldest trick in the book, a restart of the database server resolved this issue.

Reg - Thanks for taking a look at this, I appreciate it!