Intermitent Broker rejects connection

[Marco Aurelio Soares]

Dear all,
we have this scenário:
1) DB Progress 10.2B runing over AIX server started with script and configured with secondary broker to allow SAL92 ODBC connection. It is in the last service pack
2) one Windows 2008 64bits virtual server where we configured the system DSN to connect to the database
3) the application is an ASP webpage running over IIS in the above server
Some times there are no problem and the application runs very well during a long time, some time we get the error: "Broker rejects connection" and "Database is already connected"
How can I debug this error?

 

[RealHeavyDude]

What does the database log file ( file with the extension lg residing in the same directory where the .db is residing ) say?

Heavy Regards, RealHeavyDude.

 

[Marco Aurelio Soares]

Hello,


[2014/03/19@10:16:02.725-0300] P-27263162 T-849 I SRV 5: (8873) Login usernum 222, remote SQL client.
[2014/03/19@10:16:02.743-0300] P-27263162 T-849 I SRV 5: (7129) Usr 222 define name for sysprogress.
[2014/03/19@10:16:02.778-0300] P-27263162 T-594 I SRV 5: (8873) Login usernum 220, remote SQL client.
[2014/03/19@10:16:02.796-0300] P-27263162 T-594 I SRV 5: (7129) Usr 220 define name for .
[2014/03/19@10:16:02.796-0300] P-27263162 T-594 I SQLSRV2 5: (-----) Error authenticating user : no user-id on the command line
[2014/03/19@10:16:02.797-0300] P-27263162 T-594 I SRV 5: (453) Logout by no .
[2014/03/19@10:16:02.799-0300] P-27263162 T-849 I SRV 5: (453) Logout por sysprogress no .
[2014/03/19@10:16:12.900-0300] P-7274682 T-1 I BROKER 0: (8839) No SQL servers are available. Try again later.

 

[TomBascom]

Do you have a reason to think that:

(8839) No SQL servers are available. Try again later.

is inaccurate?

Usually it means exactly what it says -- there are no more. Probably because they are all in use.

To debug that we need to know how you have configure your servers. Find the portion of the .lg file immediately after the last instance of message (333) down to where it says that the db is up and running and post it (within CODE tags so that it is readable). That will tell us how many servers there are and how they have been configured. Which may go a long ways towards figuring out the issue.

 

[Marco Aurelio Soares]

Please, tell me if I need to translate to English:

[2014/02/16@19:27:18.807-0300] P-7274682 T-1 I BROKER 0: (333) Inicio de sessão multi-usuário.
[2014/02/16@19:27:18.811-0300] P-7274682 T-1 I BROKER 0: (15321) Inicialização do log Before Image no bloco 0 offset 235.
[2014/02/16@19:27:19.310-0300] P-7274682 T-1 I BROKER 0: (452) Login por root no /dev/pts/1.
[2014/02/16@19:27:19.312-0300] P-7274682 T-1 I BROKER 0: (5644) Iniciado para 30122 usando TCP IPV4 address 0.0.0.0, pid 7274682.
[2014/02/16@19:27:20.313-0300] P-7274682 T-1 I BROKER 0: (4234) PROGRESS OpenEdge versão 10.2B build 1699 SP07 em AIX rb3pd12 1 6 00C553524C00.
[2014/02/16@19:27:20.313-0300] P-7274682 T-1 I BROKER 0: (4281) Servidor iniciado por root em /dev/pts/1.
[2014/02/16@19:27:20.313-0300] P-7274682 T-1 I BROKER 0: (-----) Started using pid: 7274682.
[2014/02/16@19:27:20.313-0300] P-7274682 T-1 I BROKER 0: (4235) Nome físico da base de dados (-db): /database/oficial/ems206/ems2cad/ems2cad.
[2014/02/16@19:27:20.313-0300] P-7274682 T-1 I BROKER 0: (4236) Tipo de Base de Dados (-dt): PROGRESS.
[2014/02/16@19:27:20.314-0300] P-7274682 T-1 I BROKER 0: (4237) Acesso Forçado (-F): Not Enabled.
[2014/02/16@19:27:20.314-0300] P-7274682 T-1 I BROKER 0: (4238) Direct I/O (-directio): Not Enabled.
[2014/02/16@19:27:20.314-0300] P-7274682 T-1 I BROKER 0: (-----) LRU mechanism enabled.
[2014/02/16@19:27:20.314-0300] P-7274682 T-1 I BROKER 0: (-----) Number of LRU force skips (-lruskips): 0
[2014/02/16@19:27:20.314-0300] P-7274682 T-1 I BROKER 0: (-----) Number of LRU2 force skips (-lru2skips): 0
[2014/02/16@19:27:20.314-0300] P-7274682 T-1 I BROKER 0: (4239) Número de buffers de base de dados (-B): 240000.
[2014/02/16@19:27:20.315-0300] P-7274682 T-1 I BROKER 0: (-----) Number of Alternate Database Buffers (-B2): 0.
[2014/02/16@19:27:20.315-0300] P-7274682 T-1 I BROKER 0: (9422) Número máximo de private buffers por usuário (-Bpmax): 64.
[2014/02/16@19:27:20.315-0300] P-7274682 T-1 I BROKER 0: (4240) Excesso no Tamanho da Memória Compartilhada (-Mxs): 202.
[2014/02/16@19:27:20.315-0300] P-7274682 T-1 I BROKER 0: (10014) A área de memória compartilhada não foi travada em memória.
[2014/02/16@19:27:20.315-0300] P-7274682 T-1 I BROKER 0: (4241) Tamanho da tabela de lock (-L): 250016.
[2014/02/16@19:27:20.315-0300] P-7274682 T-1 I BROKER 0: (13953) Número máximo da área (-maxArea): 32000.
[2014/02/16@19:27:20.316-0300] P-7274682 T-1 I BROKER 0: (4242) Número de entradas na tabela de hash (-hash): 70289.
[2014/02/16@19:27:20.316-0300] P-7274682 T-1 I BROKER 0: (4243) Spin lock (-spin): 40000.
[2014/02/16@19:27:20.316-0300] P-7274682 T-1 I BROKER 0: (6526) Número de semaphore sets (-semsets) 3.
[2014/02/16@19:27:20.316-0300] P-7274682 T-1 I BROKER 0: (13924) Tamanho máximo do segmento da memória compartilhada (-shmsegsize) 2048 MB.
[2014/02/16@19:27:20.316-0300] P-7274682 T-1 I BROKER 0: (4244) Crash Recovery (-i): Enabled.
[2014/02/16@19:27:20.316-0300] P-7274682 T-1 I BROKER 0: (6573) Database Blocksize (-blocksize): 8192.
[2014/02/16@19:27:20.317-0300] P-7274682 T-1 I BROKER 0: (4245) Retardo na descarga do Before-Image (-Mf): 3.
[2014/02/16@19:27:20.317-0300] P-7274682 T-1 I BROKER 0: (4247) I/O no arquivo Before-Image (-r -R): Reliable.
[2014/02/16@19:27:20.317-0300] P-7274682 T-1 I BROKER 0: (4249) Intervalo para truncar Before-Image (-G): 0.
[2014/02/16@19:27:20.317-0300] P-7274682 T-1 I BROKER 0: (4250) Tamanho do Cluster de Before-Image: 33554432.
[2014/02/16@19:27:20.317-0300] P-7274682 T-1 I BROKER 0: (4251) Tamanho do Bloco de Before-Image: 16384.
[2014/02/16@19:27:20.317-0300] P-7274682 T-1 I BROKER 0: (4252) Numero de Buffers de Before-Image (-bibufs): 25.
[2014/02/16@19:27:20.318-0300] P-7274682 T-1 I BROKER 0: (-----) Record free chain search depth factor 5 (-recspacesearchdepth)
[2014/02/16@19:27:20.318-0300] P-7274682 T-1 I BROKER 0: (9238) Tamanho de Threshold do arquivo de BI (-bithold): 0.0 Bytes.
[2014/02/16@19:27:20.318-0300] P-7274682 T-1 I BROKER 0: (6552) Atraso no Before-Image (-bistall): Desabilitado.
[2014/02/16@19:27:20.318-0300] P-7274682 T-1 I BROKER 0: (4254) Atraso no After-Image (-aistall): Enabled.
[2014/02/16@19:27:20.318-0300] P-7274682 T-1 I BROKER 0: (4255) Tamanho do Bloco de After-Image: 8192.
[2014/02/16@19:27:20.318-0300] P-7274682 T-1 I BROKER 0: (4256) Número de buffers de After-Image (-aibufs): 25.
[2014/02/16@19:27:20.319-0300] P-7274682 T-1 I BROKER 0: (8527) Tamanho do cache de armazenamento de objeto (-omsize): 1024
[2014/02/16@19:27:20.319-0300] P-7274682 T-1 I BROKER 0: (4257) Número máximo de clientes por servidor (-Ma): 8.
[2014/02/16@19:27:20.319-0300] P-7274682 T-1 I BROKER 0: (4258) Número máximo de servidores (-Mn): 53.
[2014/02/16@19:27:20.319-0300] P-7274682 T-1 I BROKER 0: (4259) Número mínimo de clientes por servidor (-Mi): 6.
[2014/02/16@19:27:20.319-0300] P-7274682 T-1 I BROKER 0: (-----) Server network message wait time (-Nmsgwait): 2
[2014/02/16@19:27:20.319-0300] P-7274682 T-1 I BROKER 0: (-----) Delay first prefetch message (-prefetchDelay): Disabled
[2014/02/16@19:27:20.320-0300] P-7274682 T-1 I BROKER 0: (-----) Prefetch message fill percentage (-prefetchFactor): 0
[2014/02/16@19:27:20.320-0300] P-7274682 T-1 I BROKER 0: (-----) Minimum records in prefetch ms (-prefetchNumRecs): 16
[2014/02/16@19:27:20.320-0300] P-7274682 T-1 I BROKER 0: (-----) Suspension queue poll priority (-prefetchPriority): 0
[2014/02/16@19:27:20.320-0300] P-7274682 T-1 I BROKER 0: (4260) Número máximo de usuários (-n): 425.
[2014/02/16@19:27:20.320-0300] P-7274682 T-1 I BROKER 0: (4261) Nome do Host (-H): rb3pd12.
[2014/02/16@19:27:20.320-0300] P-7274682 T-1 I BROKER 0: (4262) Nome do serviço (-S): 30122.
[2014/02/16@19:27:20.321-0300] P-7274682 T-1 I BROKER 0: (14268) Versão TCP/IP (-ipver) : IPV4
[2014/02/16@19:27:20.321-0300] P-7274682 T-1 I BROKER 0: (4263) Tipo de protocolo (-N): TCP.
[2014/02/16@19:27:20.321-0300] P-7274682 T-1 I BROKER 0: (4264) Conjunto de caracteres (-cpinternal): ISO8859-1.
[2014/02/16@19:27:20.321-0300] P-7274682 T-1 I BROKER 0: (4282) Arquivo de parâmetros: Not Enabled.
[2014/02/16@19:27:20.321-0300] P-7274682 T-1 I BROKER 0: (5647) Maximo de Servers por Broker (-Mpb): 2.
[2014/02/16@19:27:20.321-0300] P-7274682 T-1 I BROKER 0: (5648) Minimo de Portas para os Auto Servers (-minport): 3000.
[2014/02/16@19:27:20.321-0300] P-7274682 T-1 I BROKER 0: (5649) Maximo de Portas para Auto Servers (-maxport): 29000.
[2014/02/16@19:27:20.322-0300] P-7274682 T-1 I BROKER 0: (8864) Este broker somente suporta servidores SQL.
[2014/02/16@19:27:20.322-0300] P-7274682 T-1 I BROKER 0: (9426) Large database file access has been enabled.
[2014/02/16@19:27:20.322-0300] P-7274682 T-1 I BROKER 0: (9336) Criado área de memória compartilhada com segment_id: 9
[2014/02/16@19:27:20.322-0300] P-7274682 T-1 I BROKER 0: (12813) Cursores de índice permitidos (-c): 1700.
[2014/02/16@19:27:20.322-0300] P-7274682 T-1 I BROKER 0: (12814) Group delay (-groupdelay): 10.
[2014/02/16@19:27:20.322-0300] P-7274682 T-1 I BROKER 0: (12815) Bloquear tamanho da tabela no hash de tabela (-lkhash): 35863
[2014/02/16@19:27:20.323-0300] P-7274682 T-1 I BROKER 0: (12816) Maxport (-maxport): 29000
[2014/02/16@19:27:20.323-0300] P-7274682 T-1 I BROKER 0: (12817) Minport (-minport): 3000
[2014/02/16@19:27:20.323-0300] P-7274682 T-1 I BROKER 0: (12818) Tamanho do Message Buffer (-Mm): 1024
[2014/02/16@19:27:20.323-0300] P-7274682 T-1 I BROKER 0: (12820) Máximo servers por broker (-Mpb): 2
[2014/02/16@19:27:20.323-0300] P-7274682 T-1 I BROKER 0: (12821) Use muxlatches (-mux): 1
[2014/02/16@19:27:20.323-0300] P-7274682 T-1 I BROKER 0: (12823) Semaphore Sets (-semsets): 3
[2014/02/16@19:27:20.324-0300] P-7274682 T-1 I BROKER 0: (13870) Database Service Manager - Tamanho da fila IPC (-pica): 64.0 KBytes.
[2014/02/16@19:27:20.324-0300] P-7274682 T-1 I BROKER 0: (13871) Método de arquivamento de gerenciamento After-image: Timed.
[2014/02/16@19:27:20.324-0300] P-7274682 T-1 I BROKER 0: (13872) Intervalo de arquivamento de gerenciamento After-image (-aiarcinterval): 1800.
[2014/02/16@19:27:20.324-0300] P-7274682 T-1 I BROKER 0: (13873) Lista de diretórios de arquivamento de gerenciamento After-image (-aiarcdir): /afterimg/tempai/oficial/ems206/ems2cad.
[2014/02/16@19:27:20.324-0300] P-7274682 T-1 I BROKER 0: (13874) Criar diretório(s) de arquivamento de gerenciamento After-image (-aiarcdircreate): No.
[2014/02/16@19:27:20.324-0300] P-7274682 T-1 I BROKER 0: (13896) Limite para ignorar o bloqueio TXE Commit (-TXESkipLimit): 10000.
[2014/02/16@19:27:20.325-0300] P-7274682 T-1 I BROKER 0: (15219) Criptografia habilitada: 0
[2014/02/16@19:27:20.325-0300] P-7274682 T-1 I BROKER 0: (15218) Tamanho do cache de criptografia (-ecsize): 1000
[2014/02/16@19:27:20.325-0300] P-7274682 T-1 I BROKER 0: (10471) Conexões de Banco de Dados foram habilitadas.
[2014/02/16@19:27:20.362-0300] P-11730958 T-1 I SRV 1: (452) Login por root no /dev/pts/1.
[2014/02/16@19:27:20.365-0300] P-11730958 T-1 I BROKER 1: (5644) Iniciado para 30102 usando TCP IPV4 address 0.0.0.0, pid 11730958.
[2014/02/16@19:27:20.366-0300] P-11730958 T-1 I BROKER 1: (5645) Este é um broker adicional para este protocolo.
[2014/02/16@19:27:20.366-0300] P-11730958 T-1 I BROKER 1: (8863) Este broker somente suporta conexões 4GL.

 

[TomBascom]

It looks like you started a SQL only broker with -Mpb 2

-Ma seems to be set to 8 which would allow a total of 16 SQL connections.

 

[Marco Aurelio Soares]

Tom, we will change -Ma and -Mpb to provide more connections.

But we found that there was some dead users still connected to the ports (PROMON “BD” R&D 1 4 1). We tried to kill the users with PROSHUT but didn't work. We had to kill the PID of the port's: "kill -9 port-PID"

 

[TomBascom]

You might want to keep -Ma under 5. I have a faint memory that on some releases SQL behaves inappropriately with larger values.

I also always use -Mi 1.