Database Log Help - 10.1B

B

BCM

Member
We have a nightly backup, shut-down, and re-start for our Progress database. Following the re-start we pull data from the Progress database to our data warehouse on SQL Server by issuing SQL SELECT statements from SQL Server to the Progress database. The job that pulls the data from Progress to the data warehouse failed this morning, and I believe it failed because the Progress database was not ready at 2:05 AM.

Below, is a copy of the entries from our Progress database log. The pertinent entries were logged at 2:05 AM. I want to know what event or command triggers those entries OR what could explain the delay between 1:03 AM and 2:05 AM.


Wed Apr 30 01:03:25 2008
[2008/04/30@01:03:25.390-0500] P-2248 T-4636 I BROKER 0: (333) Multi-user session begin.
[2008/04/30@01:03:28.249-0500] P-2248 T-4636 I BROKER 0: (5326) Begin Physical Redo Phase at 12864 .
[2008/04/30@01:03:31.031-0500] P-2248 T-4636 I BROKER 0: (7161) Physical Redo Phase Completed at blk 12956 off 7980 upd 0.
[2008/04/30@01:03:31.031-0500] P-2248 T-4636 I BROKER 0: (13547) At end of Physical redo, transaction table size is 256.
[2008/04/30@01:03:31.140-0500] P-2248 T-4636 I BROKER 0: (5644) Started for 2501 using TCP, pid 2248.
[2008/04/30@01:03:31.140-0500] P-2248 T-4636 I BROKER 0: (8836) Connecting to Admin Server on port 7839.
[2008/04/30@01:03:31.156-0500] P-2248 T-4636 I BROKER 0: (8846) Registered with Admin Server.
[2008/04/30@01:03:31.156-0500] P-2248 T-4636 I BROKER 0: (4234) Progress OpenEdge Release 10.1B build 1372 SP03 on WINNT .
[2008/04/30@01:03:31.156-0500] P-2248 T-4636 I BROKER 0: (4281) Server started by SYSTEM on CON:.
[2008/04/30@01:03:31.156-0500] P-2248 T-4636 I BROKER 0: (6574) Started using pid: 2248.
[2008/04/30@01:03:31.156-0500] P-2248 T-4636 I BROKER 0: (4235) Physical Database Name (-db): d:\database\Prod\Yyyyy300.
[2008/04/30@01:03:31.156-0500] P-2248 T-4636 I BROKER 0: (4236) Database Type (-dt): PROGRESS.
[2008/04/30@01:03:31.156-0500] P-2248 T-4636 I BROKER 0: (4237) Force Access (-F): Not Enabled.
[2008/04/30@01:03:31.156-0500] P-2248 T-4636 I BROKER 0: (4238) Direct I/O (-directio): Not Enabled.
[2008/04/30@01:03:31.156-0500] P-2248 T-4636 I BROKER 0: (4239) Number of Database Buffers (-B): 40000.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (9422) Maximum private buffers per user (-Bpmax): 64.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4240) Excess Shared Memory Size (-Mxs): 16414.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (10014) The shared memory segment is not locked in memory.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4241) Current Size of Lock Table (-L): 128000.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (-----) Maximum Area Number (-maxArea): 32000.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4242) Hash Table Entries (-hash): 13063.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4243) Current Spin Lock Tries (-spin): 1000.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (6526) Number of Semaphore Sets (-semsets): 3.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (13924) Maximum Shared Memory Segment Size (-shmsegsize) 256 Mb.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4244) Crash Recovery (-i): Enabled.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (6573) Database Blocksize (-blocksize): 4096.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4245) Delay of Before-Image Flush (-Mf): 3.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4247) Before-Image File I/O (-r -R): Reliable.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4249) Before-Image Truncate Interval (-G): 0.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4250) Before-Image Cluster Size: 524288.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4251) Before-Image Block Size: 8192.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4252) Number of Before-Image Buffers (-bibufs): 20.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (-----) Record free chain search depth factor 5 (-recspacesearchdepth)
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (9238) BI File Threshold size (-bithold): 0.0 Bytes.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (6552) BI File Threshold Stall (-bistall): Disabled.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4254) After-Image Stall (-aistall): Not Enabled.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4255) After-Image Block Size: 8192.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4256) Number of After-Image Buffers (-aibufs): 20.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (8527) Storage object cache size (-omsize): 1024
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4257) Maximum Number of Clients Per Server (-Ma): 5.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4258) Maximum Number of Servers (-Mn): 31.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4259) Minimum Clients Per Server (-Mi): 4.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4260) Maximum Number of Users (-n): 105.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4261) Host Name (-H): Xxxx1.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4262) Service Name (-S): 2501.
[2008/04/30@01:03:31.171-0500] P-2248 T-4636 I BROKER 0: (4263) Network Type (-N): TCP.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (4264) Character Set (-cpinternal): ISO8859-1.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (4282) Parameter File: Not Enabled.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (5647) Maximum Servers Per Broker (-Mpb): 26.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (5648) Minimum Port for Auto Servers (-minport): 3000.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (5649) Maximum Port for Auto Servers (-maxport): 5000.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (8863) This broker supports 4GL server groups only.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (9336) Created shared memory with segment_id: 19005440
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (12813) Allowed index cursors (-c): 420.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (12814) Group delay (-groupdelay): 10.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (12815) Lock table hash table size (-lkhash): 18289
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (12816) Maxport (-maxport): 5000
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (12817) Minport (-minport): 3000
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (12818) Message Buffer Size (-Mm): 1024
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (12820) Maximum Servers per Broker (-Mpb): 26
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (12821) Use muxlatches (-mux): 1
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (12823) Semaphore Sets (-semsets): 3
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (13870) Database Service Manager - IPC Queue Size (-pica) : 64.0 KBytes.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (13896) TXE Commit lock skip limit (-TXESkipLimit): 10000.
[2008/04/30@01:03:31.187-0500] P-2248 T-4636 I BROKER 0: (10471) Database connections have been enabled.
[2008/04/30@01:03:31.687-0500] P-5464 T-5568 I SRV 1: (5646) Started on port 3000 using TCP, pid 5464.
[2008/04/30@01:03:32.624-0500] P-5464 T-5568 I SRV 1: (742) Login usernum 134, userid administrato, on Xxxx1.
[2008/04/30@01:03:32.624-0500] P-5464 T-5568 I SRV 1: (742) Login usernum 133, userid administrato, on Xxxx1.
[2008/04/30@01:03:33.702-0500] P-5464 T-5568 I SRV 1: (12699) Database Yyyyy Options:
[2008/04/30@01:03:33.702-0500] P-5464 T-5568 I SRV 1: (-----) Previous message sent on behalf of user 134, server pid 5464, broker pid 2248
[2008/04/30@01:03:33.718-0500] P-6128 T-1076 I BROKER 2: (5644) Started for 2509 using TCP, pid 6128.
[2008/04/30@01:03:33.718-0500] P-6128 T-1076 I BROKER 2: (5645) This is an additional broker for this protocol.
[2008/04/30@01:03:33.718-0500] P-6128 T-1076 I BROKER 2: (8864) This broker supports SQL server groups only.
[2008/04/30@01:03:33.718-0500] P-5464 T-5568 I SRV 1: (12699) Database Yyyyy Options:
[2008/04/30@01:03:33.718-0500] P-5464 T-5568 I SRV 1: (-----) Previous message sent on behalf of user 133, server pid 5464, broker pid 2248
[2008/04/30@01:03:35.734-0500] P-5176 T-1464 I BROKER 3: (5644) Started for 5018 using TCP, pid 5176.
[2008/04/30@01:03:35.734-0500] P-5176 T-1464 I BROKER 3: (5645) This is an additional broker for this protocol.
[2008/04/30@01:03:35.734-0500] P-5176 T-1464 I BROKER 3: (8864) This broker supports SQL server groups only.
[2008/04/30@01:03:37.749-0500] P-4104 T-4708 I BIW 31: (2518) Started.
[2008/04/30@01:03:39.702-0500] P-4052 T-5484 I WDOG 32: (2518) Started.
[2008/04/30@01:03:41.702-0500] P-3972 T-4196 I APW 33: (2518) Started.
[2008/04/30@02:05:01.669-0500] P-476 T-4296 I SQLSRV2 4: (-----) SQL Server 10.1B.03 started, configuration: "prod.defaultconfiguration"
[2008/04/30@02:05:01.731-0500] P-476 T-4296 I SQLSRV2 4: (-----) "SQL92" started on port 3001, pid 476 (0x000001dc).
[2008/04/30@02:05:01.731-0500] P-476 T-4296 I SQLSRV2 4: (-----) Thread stack size: 1024000 (bytes).
[2008/04/30@02:05:01.731-0500] P-476 T-4296 I SQLSRV2 4: (-----) DLC from ENVIRONMENT VARIABLE is: C:\PROGRESS\OPENEDGE
[2008/04/30@02:05:01.731-0500] P-476 T-4296 I SQLSRV2 4: (-----) WRKDIR from REGISTRY is: C:\OpenEdge\WRK\
[2008/04/30@02:05:01.731-0500] P-476 T-4296 I SQLSRV2 4: (-----) JDKHOME from REGISTRY is: C:\Progress\OpenEdge\jdk
[2008/04/30@02:05:01.731-0500] P-476 T-4296 I SQLSRV2 4: (-----) JREHOME from REGISTRY is: C:\Progress\OpenEdge\jre
[2008/04/30@02:05:01.731-0500] P-476 T-4296 I SQLSRV2 4: (-----) CLASSPATH from ENVIRONMENT VARIABLE is: C:\YyyyyPRG\o4glrt.zip;C:\YyyyyPRG\progress.jar;C:\YyyyyPRG\messages.jar;C:\YyyyyPRG\prowin.jar
[2008/04/30@02:05:01.731-0500] P-476 T-4296 I SQLSRV2 4: (-----) PROSQL_LOCKWAIT_TIMEOUT value is: 5 seconds
 
Hi BCM,

The entries at 2:05 are normal entries for starting up a _sqlsrv2 proces. Normally after that something like:
SRV 4: (8873) Login usernum xx, remote SQL client.
appears in the log. That would be the proces which pulls data from your Progress database. Is that entry in the logfiles?
If not maybe you got a firewall issue? Are you sure that not only the broker ports but also the server ports are opened? (IF there is a firewall). No other entries in the db log file?

Regards,

Casper.
 
You must log in or register to reply here.
Back
Top