Клиентский процесс не зарегистрирован сервером : Супермаг Плюс (Супермаг 2000)

alicedr · █ 07.04.2014 13:29

Windows Server 2008R2 x64, Oracle 11.201 Enterprise, Oracle Client 11.201 x32, Супермаг 1.030 sp5. На сервере больше ничего нет.
Сервер свежеустановленный, после проблем, описанных в System.Data.OracleClient requires Oracle client software version 8.1.7 or greater

Переключатель БД-тест БД: Тест базы данных "бд" успешен
Администратор: (при старте сообщение "Текущая лицензия ... истекает 10.04.2014"): бд-конфигурация-могу менять и сохранять настройки, добавлять-удалять места хранения;
Администратор: Права доступа-могу менять имя и пароль пользователя, ставить-снимать галочки (то есть все что могу придумать, все делается)
Администратор сервера приложения: лицензия загружается, параметры БД открываются, база активируется, по кнопке ДАЛЕЕ: активны 3 сессии: локальная служба БД, служба СП и служба лицензирования Супермага. Время бездействия у первой 0, у второй 0-60сек, у последней уже 55минут.
Супермаг+ (как локально, так и спользовательского компа): Ввод пароля (при неверном пароле-"неверное имя пользователя или пароль"), внизу "подключение в БД "бд"... Подключение установлено. Чтение данных..." и сразу "Клиентский процесс не зарегистрирован сервером". Сообщения "Текущая лицензия ... истекает" не выдает (при запуске этой же базы с этим же ключом и лицензией на другом сервере такое сообщение появляется).

"PL/SQL Developer (с пользовательского компьютера): с базой соединяется, никаких нестандартов в поведении нет, в сессиях видны все 3 сессии серсера приложений. Инвалидных обьектов в БД нет.
В логе Оракла ошибок нет.
В логе листенера все пучком:

Код:

07-APR-2014 12:51:31 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=NVM1)(CID=(PROGRAM=C:\SM2000\Bin\Sm.Main.exe)(HOST=USER_COMP)(USER=USER1))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.1.132)(PORT=54195)) * establish * NVM1 * 0
07-APR-2014 12:51:32 * (CONNECT_DATA=(SERVER=DEDICATED)(SERVICE_NAME=NVM1)(CID=(PROGRAM=C:\SM2000\Bin\Sm.Main.exe)(HOST=USER_COMP)(USER=USER1))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.1.132)(PORT=54196)) * establish * NVM1 * 0

То есть все работает, кроме собственно Супермага для пользователей:

Код:

2014.04.07 (понедельник) 11:51:32 1.30.0.0 Sm.Main
----- Прерывание работы программы -----
сообщение: "ORA-20017: Клиентский процесс не зарегистрирован сервером
ORA-06512: at "SUPERMAG.CORE", line 301
ORA-06512: at "SUPERMAG.CORE", line 1503
ORA-06512: at line 1
"
исключение: System.Data.OracleClient.OracleException
источник: System.Data.OracleClient
метод: Void CheckError(System.Data.OracleClient.OciErrorHandle, Int32)
   at System.Data.OracleClient.OracleConnection.CheckError(OciErrorHandle errorHandle, Int32 rc)

ПОЧЕМУ??

baggio · █ 07.04.2014 13:34

Цитата:

alicedr ➤
ПОЧЕМУ??

а кто сказал что можно использовать 11.2.0.1 ???
вроде как сильно не рекомендуется...

alicedr · █ 07.04.2014 13:40

Цитата:

baggio ➤ а кто сказал что можно использовать 11.2.0.1 ???
вроде как сильно не рекомендуется...

1. Данная связка у нас успешно используется на более чем 30 серверах
2. На 11.203 ошибка та же и там же. И изначально ставился именно 11.203, но ввиду отсутствия "обкатанности" этой версии конкретно у нас, сейчас обсуждается 11.201. Однако могу привести логи обеих версий. Если надо.

Dim · █ 07.04.2014 13:42

что в журнале ошибок сервера приложений? в alert.log?

Mtirt · █ 07.04.2014 13:45

В sseventlog ничего не написано?
Покажите содержимое spfile, на всякий случай...

Mtirt · █ 07.04.2014 13:49

А еще содержимое tnsnames.ora из всех home установленных на сервере и на клиентском компьютере.
Ну и sqlnet.ora тоже можно привести сюда.

alicedr · █ 07.04.2014 14:06

Цитата:

Mtirt ➤ В sseventlog ничего не написано?
Покажите содержимое spfile, на всякий случай...

EventLog-ничего свеженького
spfile - привожу pfile, с которым бд поднималась:

нет, к сожалению, не привожу, т.к. мне постоянно вылазит предупреждение "вы пытаетесь разместить ссылку на сторонний ресурс", не могу понять, где оно его находит в инит.ора
Сейчас попробую как-то преобразовать.
Но орадим в своем логе ошибок тоже не пишет:

Код:

Mon Apr 07 11:01:22 2014
C:\SM2000\oraSRV\bin\oradim.exe -startup -sid nv1 -usrpwd * -pfile c:\sm2000\orasrv\database\initnv1.ora -log oradim.log -nocheck 0 

Mon Apr 07 11:58:57 2014
C:\SM2000\oraSRV\bin\oradim.exe -shutdown -sid nv1 -usrpwd * -shutmode immediate -log oradim.log

alicedr · █ 07.04.2014 14:11

Цитата:

Dim ➤ что в журнале ошибок сервера приложений? в alert.log?

Журнал ошибок сервера приложений-это C:\SM2000\Data\SmErrorLog1404.txt? В этой папке это единственный файл, состоит из ошибочек, уже приводимых ранее:

Код:

2014.04.07 (понедельник) 13:55:24 1.30.0.0 Sm.Main
----- Прерывание работы программы -----
сообщение: "ORA-20017: Клиентский процесс не зарегистрирован сервером
ORA-06512: at "SUPERMAG.CORE", line 301
ORA-06512: at "SUPERMAG.CORE", line 1503
ORA-06512: at line 1
"
исключение: System.Data.OracleClient.OracleException
источник: System.Data.OracleClient
метод: Void CheckError(System.Data.OracleClient.OciErrorHandle, Int32)
   at System.Data.OracleClient.OracleConnection.CheckError(OciErrorHandle errorHandle, Int32 rc)

Текст полностью привести не могу из-за нарушения правил форума, ссылка на внешний ресурс (уж не знаю где)

alicedr · █ 07.04.2014 14:18

Цитата:

Dim ➤ в alert.log?

Написала ж, что нет ошибок, большой он очень. Еще и логов наколбасил:

Код:

Mon Apr 07 11:36:21 2014
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 3
Using LOG_ARCHIVE_DEST_1 parameter default value as USE_DB_RECOVERY_FILE_DEST
Autotune of undo retention is turned on. 
IMODE=BR
ILAT =27
LICENSE_MAX_USERS = 0
SYS auditing is disabled
Starting up:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options.
Using parameter settings in server-side pfile C:\SM2000\ORASRV\DATABASE\INITNV1.ORA
System parameters with non-default values:
  processes                = 150
  memory_target            = 1232M
  control_files            = "D:\DATA\SUPERMAG\NV1\NV1\CONTROL01.CTL"
  control_files            = "D:\DATA\SUPERMAG\NV1\NV1\CONTROL02.CTL"
  db_block_size            = 8192
  compatible               = "11.2.0.0.0"
  db_recovery_file_dest    = "d:\ora_archivelog\"
  db_recovery_file_dest_size= 45G
  undo_tablespace          = "UNDOTBS1"
  O7_DICTIONARY_ACCESSIBILITY= TRUE
  remote_login_passwordfile= "EXCLUSIVE"
  db_domain                = ""
  dispatchers              = "(PROTOCOL=TCP) (SERVICE=NV1XDB)"
  audit_file_dest          = "D:\DATA\SUPERMAG\NV1\ADMIN\NV1\ADUMP"
  audit_trail              = "DB"
  audit_trail              = "EXTENDED"
  db_name                  = "NOVUSM1"
  open_cursors             = 300
  diagnostic_dest          = "D:\DATA\SUPERMAG\NV1"
Mon Apr 07 11:36:21 2014
PMON started with pid=2, OS id=1340 
Mon Apr 07 11:36:21 2014
VKTM started with pid=3, OS id=3540 at elevated priority
VKTM running at (10)millisec precision with DBRM quantum (100)ms
Mon Apr 07 11:36:21 2014
GEN0 started with pid=4, OS id=3220 
Mon Apr 07 11:36:21 2014
DIAG started with pid=5, OS id=4052 
Mon Apr 07 11:36:21 2014
DBRM started with pid=6, OS id=2524 
Mon Apr 07 11:36:21 2014
PSP0 started with pid=7, OS id=3876 
Mon Apr 07 11:36:21 2014
DIA0 started with pid=8, OS id=2568 
Mon Apr 07 11:36:21 2014
MMAN started with pid=9, OS id=3856 
Mon Apr 07 11:36:21 2014
DBW0 started with pid=10, OS id=588 
Mon Apr 07 11:36:21 2014
LGWR started with pid=11, OS id=3400 
Mon Apr 07 11:36:21 2014
CKPT started with pid=12, OS id=2916 
Mon Apr 07 11:36:21 2014
SMON started with pid=13, OS id=3660 
Mon Apr 07 11:36:21 2014
RECO started with pid=14, OS id=2072 
Mon Apr 07 11:36:21 2014
MMON started with pid=15, OS id=3200 
starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
Mon Apr 07 11:36:21 2014
MMNL started with pid=16, OS id=3188 
starting up 1 shared server(s) ...
ORACLE_BASE from environment = D:\DATA\SUPERMAG
Mon Apr 07 11:36:21 2014
ALTER DATABASE   MOUNT
Successful mount of redo thread 1, with mount id 3956536565
Database mounted in Exclusive Mode
Lost write protection disabled
Completed: ALTER DATABASE   MOUNT
Mon Apr 07 11:36:25 2014
ALTER DATABASE OPEN
LGWR: STARTING ARCH PROCESSES
Mon Apr 07 11:36:25 2014
ARC0 started with pid=20, OS id=1860 
ARC0: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
ARC0: STARTING ARCH PROCESSES
Mon Apr 07 11:36:26 2014
ARC1 started with pid=21, OS id=856 
Mon Apr 07 11:36:26 2014
ARC2 started with pid=22, OS id=2156 
ARC1: Archival started
Mon Apr 07 11:36:26 2014
ARC3 started with pid=23, OS id=3208 
ARC2: Archival started
ARC1: Becoming the 'no FAL' ARCH
ARC1: Becoming the 'no SRL' ARCH
ARC2: Becoming the heartbeat ARCH
Thread 1 opened at log sequence 6804
  Current log# 3 seq# 6804 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
SMON: enabling cache recovery
Successfully onlined Undo Tablespace 2.
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is CL8MSWIN1251
No Resource Manager plan active
ARC3: Archival started
ARC0: STARTING ARCH PROCESSES COMPLETE
Starting background process QMNC
Mon Apr 07 11:36:30 2014
QMNC started with pid=24, OS id=3832 
Completed: ALTER DATABASE OPEN
Mon Apr 07 11:36:34 2014
Starting background process CJQ0
Mon Apr 07 11:36:34 2014
CJQ0 started with pid=29, OS id=320 
Mon Apr 07 11:36:39 2014
Thread 1 advanced to log sequence 6805 (LGWR switch)
  Current log# 1 seq# 6805 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Mon Apr 07 11:36:39 2014
Archived Log entry 2277 added for thread 1 sequence 6804 ID 0x71454733 dest 1:
Mon Apr 07 11:36:40 2014
db_recovery_file_dest_size of 46080 MB is 25.14% used. This is a
user-specified limit on the amount of space that will be used by this
database for recovery-related files, and does not reflect the amount of
space available in the underlying filesystem or ASM diskgroup.
Thread 1 advanced to log sequence 6806 (LGWR switch)
  Current log# 2 seq# 6806 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO02.LOG
Mon Apr 07 11:36:46 2014
Archived Log entry 2278 added for thread 1 sequence 6805 ID 0x71454733 dest 1:
Mon Apr 07 11:37:06 2014
SERVER COMPONENT id=UTLRP_BGN: timestamp=2014-04-07 11:37:06
Mon Apr 07 11:37:09 2014
Thread 1 cannot allocate new log, sequence 6807
Private strand flush not complete
  Current log# 2 seq# 6806 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO02.LOG
Thread 1 advanced to log sequence 6807 (LGWR switch)
  Current log# 3 seq# 6807 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Mon Apr 07 11:37:14 2014
Archived Log entry 2279 added for thread 1 sequence 6806 ID 0x71454733 dest 1:
Mon Apr 07 11:37:32 2014
Thread 1 cannot allocate new log, sequence 6808
Checkpoint not complete
  Current log# 3 seq# 6807 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Thread 1 advanced to log sequence 6808 (LGWR switch)
  Current log# 1 seq# 6808 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Mon Apr 07 11:37:36 2014
Archived Log entry 2280 added for thread 1 sequence 6807 ID 0x71454733 dest 1:
Mon Apr 07 11:37:42 2014
Thread 1 advanced to log sequence 6809 (LGWR switch)
  Current log# 2 seq# 6809 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO02.LOG
Mon Apr 07 11:37:43 2014
Archived Log entry 2281 added for thread 1 sequence 6808 ID 0x71454733 dest 1:
Thread 1 advanced to log sequence 6810 (LGWR switch)
  Current log# 3 seq# 6810 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Mon Apr 07 11:37:49 2014
Archived Log entry 2282 added for thread 1 sequence 6809 ID 0x71454733 dest 1:
Mon Apr 07 11:37:57 2014
Thread 1 cannot allocate new log, sequence 6811
Checkpoint not complete
  Current log# 3 seq# 6810 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Thread 1 advanced to log sequence 6811 (LGWR switch)
  Current log# 1 seq# 6811 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Mon Apr 07 11:38:00 2014
Archived Log entry 2283 added for thread 1 sequence 6810 ID 0x71454733 dest 1:
Thread 1 cannot allocate new log, sequence 6812
Checkpoint not complete
  Current log# 1 seq# 6811 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Thread 1 advanced to log sequence 6812 (LGWR switch)
  Current log# 2 seq# 6812 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO02.LOG
Mon Apr 07 11:38:07 2014
Archived Log entry 2284 added for thread 1 sequence 6811 ID 0x71454733 dest 1:
Mon Apr 07 11:38:12 2014
Thread 1 advanced to log sequence 6813 (LGWR switch)
  Current log# 3 seq# 6813 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Mon Apr 07 11:38:14 2014
Archived Log entry 2285 added for thread 1 sequence 6812 ID 0x71454733 dest 1:
Thread 1 advanced to log sequence 6814 (LGWR switch)
  Current log# 1 seq# 6814 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Mon Apr 07 11:38:19 2014
Archived Log entry 2286 added for thread 1 sequence 6813 ID 0x71454733 dest 1:
Mon Apr 07 11:38:25 2014
Thread 1 cannot allocate new log, sequence 6815
Checkpoint not complete
  Current log# 1 seq# 6814 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Thread 1 advanced to log sequence 6815 (LGWR switch)
  Current log# 2 seq# 6815 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO02.LOG
Mon Apr 07 11:38:28 2014
Archived Log entry 2287 added for thread 1 sequence 6814 ID 0x71454733 dest 1:
Thread 1 advanced to log sequence 6816 (LGWR switch)
  Current log# 3 seq# 6816 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Mon Apr 07 11:38:36 2014
Archived Log entry 2288 added for thread 1 sequence 6815 ID 0x71454733 dest 1:
Mon Apr 07 11:38:43 2014
Thread 1 cannot allocate new log, sequence 6817
Checkpoint not complete
  Current log# 3 seq# 6816 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Thread 1 advanced to log sequence 6817 (LGWR switch)
  Current log# 1 seq# 6817 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Mon Apr 07 11:38:48 2014
Archived Log entry 2289 added for thread 1 sequence 6816 ID 0x71454733 dest 1:
Mon Apr 07 11:38:56 2014
Thread 1 advanced to log sequence 6818 (LGWR switch)
  Current log# 2 seq# 6818 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO02.LOG
Mon Apr 07 11:38:58 2014
Archived Log entry 2290 added for thread 1 sequence 6817 ID 0x71454733 dest 1:
Mon Apr 07 11:39:07 2014
Thread 1 advanced to log sequence 6819 (LGWR switch)
  Current log# 3 seq# 6819 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Mon Apr 07 11:39:09 2014
Archived Log entry 2291 added for thread 1 sequence 6818 ID 0x71454733 dest 1:
Thread 1 advanced to log sequence 6820 (LGWR switch)
  Current log# 1 seq# 6820 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Mon Apr 07 11:39:17 2014
Archived Log entry 2292 added for thread 1 sequence 6819 ID 0x71454733 dest 1:
Mon Apr 07 11:39:24 2014
Thread 1 cannot allocate new log, sequence 6821
Checkpoint not complete
  Current log# 1 seq# 6820 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Thread 1 advanced to log sequence 6821 (LGWR switch)
  Current log# 2 seq# 6821 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO02.LOG
Mon Apr 07 11:39:26 2014
Archived Log entry 2293 added for thread 1 sequence 6820 ID 0x71454733 dest 1:
Mon Apr 07 11:39:38 2014
Thread 1 advanced to log sequence 6822 (LGWR switch)
  Current log# 3 seq# 6822 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO03.LOG
Mon Apr 07 11:39:38 2014
Archived Log entry 2294 added for thread 1 sequence 6821 ID 0x71454733 dest 1:
Mon Apr 07 11:39:51 2014
Thread 1 advanced to log sequence 6823 (LGWR switch)
  Current log# 1 seq# 6823 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO01.LOG
Mon Apr 07 11:39:54 2014
Archived Log entry 2295 added for thread 1 sequence 6822 ID 0x71454733 dest 1:
Mon Apr 07 11:40:39 2014
SERVER COMPONENT id=UTLRP_END: timestamp=2014-04-07 11:40:39
Mon Apr 07 11:41:28 2014
Starting background process SMCO
Mon Apr 07 11:41:28 2014
SMCO started with pid=50, OS id=2840 
Mon Apr 07 11:47:02 2014
Thread 1 advanced to log sequence 6824 (LGWR switch)
  Current log# 2 seq# 6824 mem# 0: D:\DATA\SUPERMAG\NV1\NV1\REDO02.LOG
Mon Apr 07 11:47:04 2014
Archived Log entry 2296 added for thread 1 sequence 6823 ID 0x71454733 dest 1:
Mon Apr 07 11:58:58 2014
Shutting down instance (immediate)
Stopping background process SMCO
Shutting down instance: further logons disabled
Stopping background process QMNC
Mon Apr 07 11:58:59 2014
Stopping background process CJQ0
Stopping background process MMNL
Stopping background process MMON
License high water mark = 21
Stopping Job queue slave processes, flags = 7
Job queue slave processes stopped
All dispatchers and shared servers shutdown
alter database close normal
Mon Apr 07 11:59:04 2014
SMON: disabling tx recovery
SMON: disabling cache recovery
Mon Apr 07 11:59:04 2014
Shutting down archive processes
Archiving is disabled
Mon Apr 07 11:59:04 2014
ARCH shutting down
ARC2: Archival stopped
Mon Apr 07 11:59:04 2014
ARCH shutting down
ARC1: Archival stopped
Mon Apr 07 11:59:04 2014
ARCH shutting down
ARC0: Archival stopped
Mon Apr 07 11:59:04 2014
ARCH shutting down
ARC3: Archival stopped
Thread 1 closed at log sequence 6824
Successful close of redo thread 1
Completed: alter database close normal
alter database dismount
Completed: alter database dismount
ARCH: Archival disabled due to shutdown: 1089
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
Mon Apr 07 11:59:07 2014
Stopping background process VKTM: 
ARCH: Archival disabled due to shutdown: 1089
Shutting down archive processes
Archiving is disabled
Archive process shutdown avoided: 0 active
Mon Apr 07 11:59:10 2014
Instance shutdown complete

OlegON · █ 07.04.2014 14:40

11.2.0.1 - плохо
описываем, как получается следующее выполняем все сразу и с одним пользователем, все работы на сервере с локальной консоли:
1. Останавливаем и запускаем сервер приложений (баночка зеленая)
2. Пытаемся подключиться к базе в базовом модуле, если получается ошибка - приводим алертлог за время с п.1 по последнюю строку. Если не получается текстом - можно вложением к сообщению. Внимательно смотрим, что ни в одном журнале Windows никаких красных сообщений с времени п.1 не произошло.

очень похоже, что клиент, т.е. Сервер приложений, отваливается, потому, что криво установили винду, Oracle или сервер с несколькими интерфейсами, часть из которых скачет.