AnsweredAssumed Answered

Port unregister from active probe alarm_enrichment

Question asked by GuanHua1378 on Jul 3, 2018
Latest reply on Jul 6, 2018 by GuanHua1378

Hi

 

I am experiencing restart of alarm_enrichment probe randomly for months.

Sometime it trigger a "Port unregister from active probe alarm_enrichment" alarm message to nas.

On 25 Jun there was a power cycle of the virtual machine and it seem no such alarm was receive from nas as of 4 Jun.

Although in the logs there is still indication of restart of alarm_enrichment as of 1 Jun.

Admin Console also only indicate restart of alarm_enrichment probe on 1 Jun.

Nas probe did not indicate any restart in admin console

 

I want to know what is causing a restart of alarm_enrichment below is a section of the log of ( alarm_enrichment, nas, controller ) at level 3

 

OS / CPU and memory specifications of the Primary hub OS Windows Server 2008 R2 Enterprise 8 (4 processers ) with 10 GB RAM Memory ( VMware Virtual Machine )
Version of UIM 8.50
Version of nas probe version 8.42
Version of hub and controller on the Primary hub where this nas probe is running Hub Version 7.80 , Controller 7.80

 

I have log a case with CA but would want a some view and suggestion from the communities.

 

Alarm enrichment log indicate stop at Jul 01 22:14:51:852
Jul 01 22:14:41:893 [pool-1-thread-17, alarm_enrichment] CmdbMessageEnricher: processAlarm matched on field: prid
Jul 01 22:14:41:893 [pool-1-thread-17, alarm_enrichment] AlarmEnrichmentService: Forwarding alarm to alarmEnricher 3
Jul 01 22:14:41:893 [pool-1-thread-17, alarm_enrichment] AlarmEnrichmentService: Forwarding alarm to alarmEnricher 4
Jul 01 22:14:41:893 [pool-1-thread-17, alarm_enrichment] AlarmRouter: 1 is posting message with subject 'alarm2'
Jul 01 22:14:51:852 [main, alarm_enrichment] ****************[ Stopped ]****************
Jul 01 22:14:51:852 [main, alarm_enrichment] Nas: Shutdown requested by 'run.exit'
Jul 01 22:14:52:939 [main, alarm_enrichment] CmdbMessageEnricherError closing : 'os_enricher' problem: null
Jul 01 22:14:52:940 [main, alarm_enrichment] CmdbMessageEnricherError closing : 'os_enricher' problem: null
Jul 01 22:14:52:940 [main, alarm_enrichment] CmdbMessageEnricherError closing : 'os_enricher' problem: null
Jul 01 22:14:52:952 [main, alarm_enrichment] Nas: Shutdown complete in 599ms
ul 01 22:14:54:862 [main, alarm_enrichment] ****************[ Starting ]****************
Jul 01 22:14:54:867 [main, alarm_enrichment] 8.42
Jul 01 22:14:55:005 [main, alarm_enrichment] Nas: Starting: Alarm Enrichment Process
Jul 01 22:14:55:073 [main, alarm_enrichment] CmdbJdbcDataSource: GenericCmdbJdbcDataSource intializing with config path enrichment-source/cmdbs/os_enricher
Jul 01 22:14:55:075 [main, alarm_enrichment] CmdbJdbcDataSource: connecting to database
Jul 01 22:14:56:010 [main, alarm_enrichment] AlarmEnrichmentService: reXXXtering Alarm Matchers
Jul 01 22:14:56:014 [prepopulationTimer, alarm_enrichment] prepopulate cache start: os_enricher
Jul 01 22:14:56:284 [main, alarm_enrichment] RoutingService: loading all alarm routing-rules
Jul 01 22:14:56:284 [main, alarm_enrichment] RoutingService: no router-specific target set, setting router target to default hub: /XXXdom/***/***/spooler
Jul 01 22:14:56:289 [main, alarm_enrichment] RoutingService: successfully loaded alarm router '1' (true - alarm2 -true)
Jul 01 22:14:56:289 [main, alarm_enrichment] RoutingService: no router-specific target set, setting router target to default hub: /XXXdom/***/***/spooler
Jul 01 22:14:56:291 [main, alarm_enrichment] RoutingService: successfully loaded alarm router '2' (true - alarm2 -true)
Jul 01 22:14:56:335 [prepopulationTimer, alarm_enrichment] CmdbCacheEnrichmentSource: received 1555 object for prepopulation. Prepopulating Cache...
Jul 01 22:14:56:350 [prepopulationTimer, alarm_enrichment] prepopulate cache end: os_enricher
Jul 01 22:14:57:976 [main, alarm_enrichment] AlarmQueueReader: Connection to queue 'alarm' established.
Jul 01 22:14:58:205 [attach_clientsession, alarm_enrichment] AlarmQueueReader: _numberBulkReads:readCount 1:1

 

Nas log indicate called on Jul  1 22:14:51:350Jul  1 22:14:45:495 [12248] nas: dbBeginTransaction subscriber, OK - rc:0
Jul  1 22:14:45:501 [12248] nas: dbCommitTransaction subscriber, OK - rc:0
Jul  1 22:14:45:501 [12248] nas: pubCommitMonitor:  subscr_waiting:  'flushUncommitedAlarms'
Jul  1 22:14:45:501 [12248] nas: pubCommitMonitor:  subscr_released: 'flushUncommitedAlarms'
Jul  1 22:14:48:449 [2132] nas: nsLookup ip:100.***.100.57 => '100.***.100.57' in 4500ms
Jul  1 22:14:48:455 [5196] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:14:50:700 [2132] nas: nsLookup ip:***-XXXm => '***-XXXm' in 0ms
Jul  1 22:14:50:708 [5196] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:14:50:732 [5196] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:14:50:732 [5196] nas: dbsRun committed 6 requests. 0 remaining in queue...
Jul  1 22:14:50:969 [10212] nas: nimSockaddr2Ip - found ***
Jul  1 22:14:50:980 [10212] nas: (cbRestart) from ***/50531
Jul  1 22:14:50:980 [10212] nas: ----------------[ RESTART  ]----------------
Jul  1 22:14:50:980 [10212] nas: NAS Services called using mode: 0
Jul  1 22:14:50:980 [10212] nas: Waiting for Event-Processor to stop...
Jul  1 22:14:50:985 [5916] nas: NiS bridge: NTS UPDATED: nimid='CR41610909-56389' rc: 0
Jul  1 22:14:50:986 [5916] nas: NiS bridge: NA UPDATED: nimid='CR41610909-56389' rc: 0
Jul  1 22:14:51:074 [11028] nas: dbBeginTransaction actLogRun, OK - rc:0
Jul  1 22:14:51:097 [11028] nas: dbCommitTransaction actLogRun, OK - rc:0
Jul  1 22:14:51:347 [10212] nas: pubCommitMonitor:  pub_released:    'pub'
Jul  1 22:14:51:348 [8776] nas: Event-Processor terminated...
Jul  1 22:14:51:350 [10212] nas: alarm_enrichment call to '_stop' successful
Jul  1 22:14:51:350 [10212] nas: maint Maintenance Mode Terminated
Jul  1 22:14:51:350 [10212] nas: Destroying Subscriber...
Jul  1 22:14:51:376 [6596] nas: Event publisher terminated, 0 items in queue...
Jul  1 22:14:51:389 [12436] nas: The AlarmStats monitor terminated...
Jul  1 22:14:51:391 [5916] nas: NiS bridge terminated...
Jul  1 22:14:51:398 [11028] nas: Activity-Logger terminated...
Jul  1 22:14:51:398 [12136] nas: The SpoolerConnector terminated
Jul  1 22:14:51:399 [0844] nas: Transaction-Logger terminated...
Jul  1 22:14:51:502 [10212] nas: Subscriber destroyed...
Jul  1 22:14:51:502 [10212] nas: Destroying Correlation engine...
Jul  1 22:14:51:502 [12248] nas: Subscriber terminated...
Jul  1 22:14:51:904 [12388] nas: The replExporter terminated...
Jul  1 22:14:51:975 [12216] nas: The replication importer terminated...
Jul  1 22:14:52:002 [12580] nas: Rule engine terminating, 0 scripts running...
Jul  1 22:14:52:002 [12580] nas: Rule engine terminated...
Jul  1 22:14:52:002 [4052] nas: Correlation engine terminated...
Jul  1 22:14:52:432 [11256] nas: Auto-Operator scheduler terminated...
Jul  1 22:14:52:433 [10212] nas: Correlation engine destroyed...
Jul  1 22:14:52:433 [10212] nas: Destroying the NiS bridge...
Jul  1 22:14:52:438 [10212] nas: NiS bridge destroyed...
Jul  1 22:14:52:438 [10212] nas: QosBridge - waiting for thread to complete.
Jul  1 22:14:52:438 [10212] nas: QosBridge - destroyed...
Jul  1 22:14:52:438 [10212] nas: Destroying Activity-Logger...
Jul  1 22:14:52:438 [10212] nas: Activity-Logger destroyed...
Jul  1 22:14:52:438 [10212] nas: Destroying Transaction-Logger...
Jul  1 22:14:52:438 [10212] nas: Transaction-Logger destroyed...
Jul  1 22:14:52:438 [10212] nas: Destroying Replication engine...
Jul  1 22:14:54:327 [0720] nas: Replication engine terminated...
Jul  1 22:14:54:327 [10212] nas: Replication engine destroyed...
Jul  1 22:14:54:327 [10212] nas: maint Maintenance Mode Destroyed
Jul  1 22:14:54:327 [10212] nas: Destroying Event publisher...
Jul  1 22:14:54:327 [10212] nas: Event publisher destroyed...
Jul  1 22:14:54:327 [10212] nas: Destroying NameService...
Jul  1 22:14:55:201 [2132] nas: nsLookup ip:100.***.100.56 => '100.***.100.56' in 4501ms
Jul  1 22:14:55:201 [2132] nas: NameService housekeeping is done in 2674644ms, 1724 records processed.
Jul  1 22:14:55:203 [5196] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:14:55:210 [5196] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:14:55:210 [5196] nas: dbsRun committed 1 requests. 0 remaining in queue...
Jul  1 22:14:55:701 [2132] nas: NameService terminated...
Jul  1 22:14:55:703 [10212] nas: NameService destroyed...
Jul  1 22:14:55:703 [10212] nas: Destroying Database service...
Jul  1 22:14:55:710 [5196] nas: Database service terminated...
Jul  1 22:14:55:710 [10212] nas: Database service destroyed...
Jul  1 22:14:55:715 [10212] nas: ------------[ RESTART COMPLETED ]-------------
Jul  1 22:14:55:715 [10212] nas: NAS Services called using mode: 1
Jul  1 22:14:55:715 [5840] nas: [0x01ABB960] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:55:717 [10212] nas: maint Maintenance Mode Initialized
Jul  1 22:14:55:717 [11076] nas: [0x01ABBAA0] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:55:718 [11076] nas: Event publisher started...
Jul  1 22:14:55:718 [5840] nas: Database service started...
Jul  1 22:14:55:718 [11224] nas: The SpoolerConnector started
Jul  1 22:14:55:718 [4416] nas: The AlarmStats monitor started...
Jul  1 22:14:55:739 [11664] nas: maint:  Successful reXXXtration to: maintenance_mode
Jul  1 22:14:55:739 [11664] nas: maint: MM State: UNHEALTHY Maintenance Mode Re-ReXXXtration **SUCCESS**
Jul  1 22:14:55:933 [10212] nas: The QosBridge initializing
Jul  1 22:14:55:934 [10212] nas: [0x18F203D0] Database provider is 'SQLITE3', database 'transactionlog.db'
Jul  1 22:14:55:934 [12320] nas: The QosBridge started
Jul  1 22:14:55:934 [12320] nas: QosBridge - terminated
Jul  1 22:14:55:950 [10212] nas: [0x1AAC0E50] Database provider is 'SQLITE3', database 'transactionlog.db'
Jul  1 22:14:55:951 [5160] nas: Activity-Logger started...
Jul  1 22:14:55:958 [11384] nas: [0x1AAD62E0] Database provider is 'SQLITE3', database 'transactionlog.db'
Jul  1 22:14:55:958 [10212] nas: corrInitialize: Last Alive Time: 1530454495
Jul  1 22:14:55:958 [11384] nas: Transaction-Logger started...
Jul  1 22:14:55:958 [11384] nas: Transaction-log database housekeeping scheduled to Mon Jul 02 00:30, 2018
Jul  1 22:14:55:964 [10212] nas: [0x1A85A3F0] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance 25 -'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance 27 -'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance 29 -'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance 30 -'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance 31 -'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Automatic cleanup of low-severity messages (3 days)'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Stops Incoming ticket sound if not new alarm'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - *** *** *** XXXing Do not remove'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Creation of incident tickets base on major, minor and critical alarm'
Jul  1 22:14:55:966 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Temp SMS Action'
Jul  1 22:14:55:967 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance1 - ***-X *.XX, *.XX2 & *.XX6 - *** 12 Dec 17 - XX'
Jul  1 22:14:55:967 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:967 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Copy of Temp SMS Action SMS trigger base on correlated events'
Jul  1 22:14:55:968 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:968 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:969 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:970 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:983 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance12 - Req by *** XX for ***5 *Memory* on 11 Oct 17 until further notice - XX'
Jul  1 22:14:55:990 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:995 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:996 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance2 - XXXapp01 and 02 req *** *** 27 Jun 2018 - ***'
Jul  1 22:14:55:997 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:999 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance13 - Req by *** 010718 2215hrs by ***'
Jul  1 22:14:55:999 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - - ***'
Jul  1 22:14:55:999 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***1 ***'
Jul  1 22:14:55:999 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:55:999 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Close Invisbile other alarm older than 30 min between 9-10am, 12-1 pm'
Jul  1 22:14:56:000 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation ***'
Jul  1 22:14:56:000 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:EMAIL critical (repost)'
Jul  1 22:14:56:003 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:56:006 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance20 - Req by *** for *** on 19 Oct 17 at 1346 hrs'
Jul  1 22:14:56:007 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance19 - req *** by *** on 260517 at 1400hrs - ***'
Jul  1 22:14:56:007 [5160] nas: Activity-log XXXistration used 6ms, status: OK
Jul  1 22:14:56:007 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance22 - *** 100.***.100.*** req *** - 27 Feb 2018 - XX'
Jul  1 22:14:56:008 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance18 - ***-a & b  Waiting for CR (***) - 12Jul2017-***'
Jul  1 22:14:56:008 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - ***'
Jul  1 22:14:56:008 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance8 - ***-a - 13Jul2017 - *** ***- XX'
Jul  1 22:14:56:008 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance7 - *** *** *** *** until )6 Dec 2017 9 pm'
Jul  1 22:14:56:009 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance17 -XXXX,XXXX 26092017 *** XX'
Jul  1 22:14:56:009 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Ticket Generation - XXXDB'
Jul  1 22:14:56:009 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance 28 - *** 100.***.100.*** req *** 2:50pm 28 June 2018 -***'
Jul  1 22:14:56:012 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance10 -***144,145, req *** - ***'
Jul  1 22:14:56:012 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Upgrade1 - SNMP Agent not responding Upgrade from Warn to Yellow if count more than 7 - *** , for all projects 2909'
Jul  1 22:14:56:012 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Close Clear alarm when it is not assigned'
Jul  1 22:14:56:016 [10212] nas: Trigger state changed to TRUE , '__INTERNAL:Maintenance9 - ***1 per *** on 2 May 18 at 0953 am - ***'
Jul  1 22:14:56:040 [10212] nas: corrInitialize: initialized state engine in 76 ms.
Jul  1 22:14:56:040 [10212] nas: [0x1A85A760] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:040 [8972] nas: Correlation engine started...
Jul  1 22:14:56:041 [3200] nas: Auto-Operator scheduler started...
Jul  1 22:14:56:041 [6608] nas: Rule engine started...
Jul  1 22:14:56:041 [6608] nas: [0x1AAD63D0] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:041 [3200] nas: Scheduler rescheduled profile:'***-XXXXX (warning every 28days)', next run Fri Jul 13 10:45, 2018
Jul  1 22:14:56:043 [10212] nas: scanning dir.: replication
Jul  1 22:14:56:043 [10212] nas: [0x1A85A620] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:043 [9688] nas: Replication engine started...
Jul  1 22:14:56:043 [12880] nas: The replImporter started...
Jul  1 22:14:56:044 [10328] nas: The replExporter started...
Jul  1 22:14:56:044 [6608] nas: ExecEvent: OVERDUE rule='Close Clear alarm when it is not assigned', trigger='internal', nimid=ZO82521146-04327, age=6338s, ACTION:close
Jul  1 22:14:56:044 [6608] nas: ExecEvent: Rule='Close Clear alarm when it is not assigned' on nimid='ZO82521146-04327' with ACTION:close, age:6338s, status:OK
Jul  1 22:14:56:049 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:14:56:054 [13288] nas: [0x0E2E5230] Database provider is 'SQLOLEDB', database 'NimsoftSLM'
Jul  1 22:14:56:063 [10212] nas: nsInitialize used 19ms to initialize.
Jul  1 22:14:56:063 [10212] nas: [0x1A85A620] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:064 [7644] nas: NameService started...
Jul  1 22:14:56:064 [5320] nas: Subscriber started, subject:'alarm2'
Jul  1 22:14:56:064 [13132] nas: [0x1AAF0530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:064 [13132] nas: Event-Processor started...
Jul  1 22:14:56:064 [10212] nas: (get_info) - called from ***/58137
Jul  1 22:14:56:064 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:076 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:14:56:076 [5840] nas: dbsRun committed 2 requests. 0 remaining in queue...
Jul  1 22:14:56:084 [10212] nas: (get_info) - called from ***/58136
Jul  1 22:14:56:084 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:089 [13132] nas: _processEvents 3 of 1000 in 24 ms.
Jul  1 22:14:56:089 [13132] nas: Event-Processor: published 3 messages in 24ms, 0 in queue.
Jul  1 22:14:56:092 [10212] nas: (get_info) - called from ***/58135
Jul  1 22:14:56:093 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:098 [10212] nas: (get_info) - called from ***/58130
Jul  1 22:14:56:098 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:101 [10212] nas: (get_info) - called from ***/58128
Jul  1 22:14:56:102 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:105 [10212] nas: (get_info) - called from ***/58125
Jul  1 22:14:56:105 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:107 [5160] nas: dbBeginTransaction actLogRun, OK - rc:0
Jul  1 22:14:56:108 [10212] nas: (get_info) - called from ***/58121
Jul  1 22:14:56:108 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:111 [10212] nas: (get_info) - called from ***/58118
Jul  1 22:14:56:111 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:114 [10212] nas: (get_info) - called from ***/58116
Jul  1 22:14:56:114 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:118 [10212] nas: (get_info) - called from ***/50604
Jul  1 22:14:56:118 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:125 [5160] nas: dbCommitTransaction actLogRun, OK - rc:0
Jul  1 22:14:56:158 [11384] nas: dbBeginTransaction tlogRun, OK - rc:0
Jul  1 22:14:56:169 [4416] nas: [0x01ACE130] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:176 [11384] nas: dbCommitTransaction tlogRun, OK - rc:0
Jul  1 22:14:56:184 [13288] nas: [0x0E2E5800] Database provider is 'SQLOLEDB', database 'NimsoftSLM'
Jul  1 22:14:56:211 [13288] nas: NiS bridge: current database provider is SQLSERVER - 6.1
Jul  1 22:14:56:224 [13288] nas: NiS bridge: Discovery version: 6.210000
Jul  1 22:14:56:225 [13288] nas: [0x0E2E57B0] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:247 [10212] nas: (get_info) - called from ***/58146
Jul  1 22:14:56:247 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:251 [10212] nas: (get_info) - called from ***/58148
Jul  1 22:14:56:251 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:753 [10212] nas: (get_info) - called from ***/58152
Jul  1 22:14:56:753 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:757 [10212] nas: (get_info) - called from ***/58154
Jul  1 22:14:56:757 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:760 [10212] nas: (get_info) - called from ***/58158
Jul  1 22:14:56:760 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:764 [10212] nas: (get_info) - called from ***/58164
Jul  1 22:14:56:764 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:767 [10212] nas: (get_info) - called from ***/58166
Jul  1 22:14:56:767 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:771 [10212] nas: (get_info) - called from ***/58170
Jul  1 22:14:56:771 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:774 [10212] nas: (get_info) - called from ***/58175
Jul  1 22:14:56:774 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:777 [10212] nas: (get_info) - called from ***/58173
Jul  1 22:14:56:777 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:781 [10212] nas: (get_info) - called from ***/58161
Jul  1 22:14:56:781 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:843 [13288] nas: [0x0E2E57B0] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:871 [10212] nas: (get_info) - called from ***/58178
Jul  1 22:14:56:871 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:875 [10212] nas: (get_info) - called from ***/58181
Jul  1 22:14:56:875 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:884 [13288] nas: [0x0E2E57B0] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:56:975 [5320] nas: Successfully attached to HUB.
Jul  1 22:14:57:136 [10212] nas: (get_info) - called from ***/50684
Jul  1 22:14:57:136 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:57:344 [13288] nas: NiS bridge: synchronized alarms in 1120ms
Jul  1 22:14:57:345 [13288] nas: [0x0E2E57B0] Database provider is 'SQLITE3', database 'transactionlog.db'
Jul  1 22:14:57:963 [13288] nas: COM Error [0x80040e2f] IDispatch error #3119 - [Microsoft OLE DB Provider for SQL Server] Violation of UNIQUE KEY constraint 'UQ__NAS_TRAN__XXXXE'. Cannot insert duplicate key in object 'dbo.NAS_TRANSACTION_SUMMARY'. The duplicate key value is (ZO82521146-04327).
Jul  1 22:14:57:963 [13288] nas: ndbTableInsert error: error, '[Microsoft OLE DB Provider for SQL Server] Violation of UNIQUE KEY constraint 'UQ__NAS_TRAN__XXXXE'. Cannot insert duplicate key in object 'dbo.NAS_TRANSACTION_SUMMARY'. The duplicate key value is (ZO82521146-04327).'
Jul  1 22:14:57:966 [13288] nas: NiS bridge: synchronized alarm transactions in 622ms
Jul  1 22:14:57:966 [13288] nas: NiS bridge started...
Jul  1 22:14:57:968 [13288] nas: NiS bridge: NTS UPDATED CLOSE: nimid='ZO82521146-04327' rc: 0
Jul  1 22:14:57:975 [5320] nas: Subscriber processed 1 msg.,0 updates the last 15s, 0.07 msg/s, queued:1
Jul  1 22:14:57:987 [13288] nas: NiS bridge: NA UPDATED CLOSE: nimid='ZO82521146-04327' rc: 0
Jul  1 22:14:58:147 [10212] nas: (get_info) - called from ***/50686
Jul  1 22:14:58:147 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:14:58:317 [13288] nas: CreateDevCS map used 267ms
Jul  1 22:14:58:324 [7644] nas: ptNetIpToHost - getaddrinfo failed for ***8
Jul  1 22:14:58:324 [7644] nas: nsLookup ip:***8 => '***8' in 2250ms
Jul  1 22:14:58:324 [7644] nas: nsLookup ip:*** => '***' in 0ms
Jul  1 22:14:58:324 [7644] nas: nsLookup ip:100.***.100.8 => '***8-XXXm' in 0ms
Jul  1 22:14:58:333 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:14:58:352 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:14:58:352 [5840] nas: dbsRun committed 3 requests. 0 remaining in queue...
Jul  1 22:14:58:981 [5320] nas: dbBeginTransaction subscriber, OK - rc:0
Jul  1 22:14:59:661 [10212] nas: (ao_status) from ***/50687
Jul  1 22:14:59:983 [5320] nas: dbCommitTransaction subscriber, OK - rc:0
Jul  1 22:14:59:983 [5320] nas: pubCommitMonitor:  subscr_waiting:  'flushUncommitedAlarms'
Jul  1 22:14:59:983 [5320] nas: pubCommitMonitor:  subscr_released: 'flushUncommitedAlarms'
Jul  1 22:15:02:363 [10212] nas: (get_info) - called from ***/58191
Jul  1 22:15:02:363 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:369 [10212] nas: (get_info) - called from ***/58197
Jul  1 22:15:02:369 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:373 [10212] nas: (get_info) - called from ***/58199
Jul  1 22:15:02:373 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:378 [10212] nas: (get_info) - called from ***/58211
Jul  1 22:15:02:378 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:381 [10212] nas: (get_info) - called from ***/58210
Jul  1 22:15:02:381 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:385 [10212] nas: (get_info) - called from ***/58209
Jul  1 22:15:02:385 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:388 [10212] nas: (get_info) - called from ***/58208
Jul  1 22:15:02:388 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:391 [10212] nas: (get_info) - called from ***/58207
Jul  1 22:15:02:391 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:395 [10212] nas: (get_info) - called from ***/58206
Jul  1 22:15:02:395 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:398 [10212] nas: (get_info) - called from ***/58205
Jul  1 22:15:02:398 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:401 [10212] nas: (get_info) - called from ***/58198
Jul  1 22:15:02:401 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:02:825 [7644] nas: nsLookup ip:*** => '***' in 4501ms
Jul  1 22:15:02:827 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:02:832 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:02:832 [5840] nas: dbsRun committed 1 requests. 0 remaining in queue...
Jul  1 22:15:05:075 [7644] nas: ptNetIpToHost - getaddrinfo failed for ***9
Jul  1 22:15:05:075 [7644] nas: nsLookup ip:***9 => '***9' in 2250ms
Jul  1 22:15:05:079 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:05:085 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:05:085 [5840] nas: dbsRun committed 1 requests. 0 remaining in queue...
Jul  1 22:15:07:983 [5320] nas: Subscriber processed 1 msg.,0 updates the last 10s, 0.10 msg/s, queued:1
Jul  1 22:15:09:577 [7644] nas: nsLookup ip:100.***.100.12 => '100.***.100.12' in 4502ms
Jul  1 22:15:09:581 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:09:588 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:09:588 [5840] nas: dbsRun committed 1 requests. 0 remaining in queue...
Jul  1 22:15:10:049 [5320] nas: dbBeginTransaction subscriber, OK - rc:0
Jul  1 22:15:10:142 [5320] nas: dbCommitTransaction subscriber, OK - rc:0
Jul  1 22:15:10:142 [5320] nas: pubCommitMonitor:  subscr_waiting:  'flushUncommitedAlarms'
Jul  1 22:15:10:142 [5320] nas: pubCommitMonitor:  subscr_released: 'flushUncommitedAlarms'
Jul  1 22:15:11:128 [13132] nas: _processEvents 1 of 1000 in 25 ms.
Jul  1 22:15:11:128 [13132] nas: Event-Processor: published 1 messages in 25ms, 0 in queue.
Jul  1 22:15:11:206 [11384] nas: dbBeginTransaction tlogRun, OK - rc:0
Jul  1 22:15:11:210 [4416] nas: [0x1A5D4AD0] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:11:242 [11384] nas: dbCommitTransaction tlogRun, OK - rc:0
Jul  1 22:15:11:827 [7644] nas: ptNetIpToHost - getaddrinfo failed for ***7
Jul  1 22:15:11:827 [7644] nas: nsLookup ip:***7 => '***7' in 2250ms
Jul  1 22:15:11:827 [7644] nas: nsLookup ip:XXXha => 'XXXha' in 0ms
Jul  1 22:15:11:835 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:11:842 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:11:842 [5840] nas: dbsRun committed 2 requests. 0 remaining in queue...
Jul  1 22:15:22:124 [10212] nas: (get_info) - called from ***/51552
Jul  1 22:15:22:124 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:22:983 [10212] nas: (ao_status) from ***/51555
Jul  1 22:15:23:078 [7644] nas: ptNetIpToHost - getaddrinfo failed for ***8
Jul  1 22:15:23:078 [7644] nas: nsLookup ip:***8 => '***8' in 2250ms
Jul  1 22:15:23:087 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:23:094 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:23:094 [5840] nas: dbsRun committed 1 requests. 0 remaining in queue...
Jul  1 22:15:26:149 [13132] nas: _processEvents 7 of 1000 in 6 ms.
Jul  1 22:15:26:149 [13132] nas: Event-Processor: published 7 messages in 6ms, 0 in queue.
Jul  1 22:15:26:153 [11384] nas: dbBeginTransaction tlogRun, OK - rc:0
Jul  1 22:15:26:162 [4416] nas: [0x0CFD5D80] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:172 [11384] nas: dbCommitTransaction tlogRun, OK - rc:0
Jul  1 22:15:26:419 [10212] nas: (get_info) - called from ***/58279
Jul  1 22:15:26:419 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:424 [10212] nas: (get_info) - called from ***/58282
Jul  1 22:15:26:424 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:429 [10212] nas: (get_info) - called from ***/58295
Jul  1 22:15:26:429 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:435 [10212] nas: (get_info) - called from ***/58302
Jul  1 22:15:26:435 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:440 [10212] nas: (get_info) - called from ***/58301
Jul  1 22:15:26:440 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:444 [10212] nas: (get_info) - called from ***/58300
Jul  1 22:15:26:444 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:449 [10212] nas: (get_info) - called from ***/58299
Jul  1 22:15:26:449 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:454 [10212] nas: (get_info) - called from ***/58298
Jul  1 22:15:26:454 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:459 [10212] nas: (get_info) - called from ***/58297
Jul  1 22:15:26:459 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:462 [10212] nas: (get_info) - called from ***/58296
Jul  1 22:15:26:462 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:465 [10212] nas: (get_info) - called from ***/58285
Jul  1 22:15:26:465 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:26:608 [5320] nas: dbBeginTransaction subscriber, OK - rc:0
Jul  1 22:15:27:027 [10212] nas: (get_info) - called from ***/58306
Jul  1 22:15:27:028 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:031 [10212] nas: (get_info) - called from ***/58309
Jul  1 22:15:27:031 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:035 [10212] nas: (get_info) - called from ***/58312
Jul  1 22:15:27:035 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:038 [10212] nas: (get_info) - called from ***/58318
Jul  1 22:15:27:038 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:042 [10212] nas: (get_info) - called from ***/58319
Jul  1 22:15:27:042 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:045 [10212] nas: (get_info) - called from ***/58326
Jul  1 22:15:27:045 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:048 [10212] nas: (get_info) - called from ***/58328
Jul  1 22:15:27:048 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:052 [10212] nas: (get_info) - called from ***/58334
Jul  1 22:15:27:052 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:055 [10212] nas: (get_info) - called from ***/58333
Jul  1 22:15:27:055 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:058 [10212] nas: (get_info) - called from ***/58323
Jul  1 22:15:27:058 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:062 [10212] nas: (get_info) - called from ***/58315
Jul  1 22:15:27:062 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:27:580 [7644] nas: nsLookup ip:100.***.100.11 => '100.***.100.11' in 4502ms
Jul  1 22:15:27:613 [5320] nas: dbCommitTransaction subscriber, OK - rc:0
Jul  1 22:15:27:613 [5320] nas: pubCommitMonitor:  subscr_waiting:  'flushUncommitedAlarms'
Jul  1 22:15:27:613 [5320] nas: pubCommitMonitor:  subscr_released: 'flushUncommitedAlarms'
Jul  1 22:15:27:613 [5320] nas: Subscriber processed 6 msg.,4 updates the last 10s, 0.60 msg/s, queued:1
Jul  1 22:15:27:622 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:27:627 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:27:627 [5840] nas: dbsRun committed 1 requests. 0 remaining in queue...
Jul  1 22:15:29:841 [7644] nas: ptNetIpToHost - getaddrinfo failed for ***6
Jul  1 22:15:29:841 [7644] nas: nsLookup ip:***6 => '***6' in 2261ms
Jul  1 22:15:29:841 [7644] nas: nsLookup ip:100.***.100.22 => '***' in 0ms
Jul  1 22:15:29:845 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:29:852 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:29:852 [5840] nas: dbsRun committed 2 requests. 0 remaining in queue...
Jul  1 22:15:30:910 [10212] nas: nimSockaddr2Ip - found ***
Jul  1 22:15:30:911 [10212] nas: (script_list) from ***/51904
Jul  1 22:15:30:911 [10212] nas: scanning dir.: scripts
Jul  1 22:15:30:911 [10212] nas: scanning dir.: scripts\examples
Jul  1 22:15:30:911 [10212] nas: match file: copy of nsdconnector-process-alarm-on-arrival
Jul  1 22:15:30:911 [10212] nas: match file: example-alarm-operations
Jul  1 22:15:30:911 [10212] nas: match file: example-correlation
Jul  1 22:15:30:911 [10212] nas: match file: example-database-operations
Jul  1 22:15:30:911 [10212] nas: match file: example-file-operations
Jul  1 22:15:30:911 [10212] nas: match file: example-get-probe-config
Jul  1 22:15:30:911 [10212] nas: match file: example-html-email-alarms
Jul  1 22:15:30:911 [10212] nas: match file: example-html-email-triggers
Jul  1 22:15:30:911 [10212] nas: match file: example-nimbus-qos
Jul  1 22:15:30:911 [10212] nas: match file: example-nimbus-request
Jul  1 22:15:30:911 [10212] nas: match file: example-note-operations
Jul  1 22:15:30:911 [10212] nas: match file: example-process-alarm-on-arrival
Jul  1 22:15:30:911 [10212] nas: match file: example-string-operations
Jul  1 22:15:30:911 [10212] nas: match file: example-time-functions
Jul  1 22:15:30:911 [10212] nas: match file: example-using-variables
Jul  1 22:15:30:911 [10212] nas: match file: example-xml-alarms
Jul  1 22:15:30:911 [10212] nas: match file: nsdconnector-process-alarm-on-arrival
Jul  1 22:15:30:911 [10212] nas: match file: resetalarmmessage
Jul  1 22:15:30:911 [10212] nas: scanning dir.: scripts\library
Jul  1 22:15:30:911 [10212] nas: match file: html-alarms-lib
Jul  1 22:15:30:911 [10212] nas: match file: xml-alarms-lib
Jul  1 22:15:31:958 [13132] nas: _processEvents 1 of 1000 in 808 ms.
Jul  1 22:15:31:958 [13132] nas: Event-Processor: published 1 messages in 808ms, 1 in queue.
Jul  1 22:15:32:003 [11384] nas: dbBeginTransaction tlogRun, OK - rc:0
Jul  1 22:15:32:009 [11384] nas: dbCommitTransaction tlogRun, OK - rc:0
Jul  1 22:15:32:094 [7644] nas: ptNetIpToHost - getaddrinfo failed for ***
Jul  1 22:15:32:094 [7644] nas: nsLookup ip:*** => '***' in 2253ms
Jul  1 22:15:32:094 [7644] nas: nsLookup ip:*** => '***' in 0ms
Jul  1 22:15:32:094 [7644] nas: nsLookup ip:*** => '***' in 0ms
Jul  1 22:15:32:094 [7644] nas: nsLookup ip:100.***.100.6 => '***6-XXXm' in 0ms
Jul  1 22:15:32:103 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:32:110 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:32:110 [5840] nas: dbsRun committed 4 requests. 0 remaining in queue...
Jul  1 22:15:32:554 [10212] nas: (get_info) - called from ***/58347
Jul  1 22:15:32:554 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:562 [10212] nas: (get_info) - called from ***/58357
Jul  1 22:15:32:562 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:566 [10212] nas: (get_info) - called from ***/58359
Jul  1 22:15:32:566 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:569 [10212] nas: (get_info) - called from ***/58358
Jul  1 22:15:32:569 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:574 [10212] nas: (get_info) - called from ***/58361
Jul  1 22:15:32:574 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:589 [10212] nas: (get_info) - called from ***/58367
Jul  1 22:15:32:589 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:592 [10212] nas: (get_info) - called from ***/58366
Jul  1 22:15:32:592 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:596 [10212] nas: (get_info) - called from ***/58365
Jul  1 22:15:32:596 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:599 [10212] nas: (get_info) - called from ***/58364
Jul  1 22:15:32:599 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:603 [10212] nas: (get_info) - called from ***/58363
Jul  1 22:15:32:603 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:32:606 [10212] nas: (get_info) - called from ***/58362
Jul  1 22:15:32:606 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:34:503 [10212] nas: (get_info) - called from ***/58370
Jul  1 22:15:34:503 [10212] nas: [0x1A85A530] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:36:595 [7644] nas: nsLookup ip:*** => '***' in 4501ms
Jul  1 22:15:36:603 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:36:608 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:36:608 [5840] nas: dbsRun committed 1 requests. 0 remaining in queue...
Jul  1 22:15:36:964 [13132] nas: _processEvents 1 of 1000 in 5 ms.
Jul  1 22:15:36:964 [13132] nas: Event-Processor: published 1 messages in 5ms, 0 in queue.
Jul  1 22:15:37:011 [4416] nas: [0x1BAE14D0] Database provider is 'SQLITE3', database 'database.db'
Jul  1 22:15:37:015 [11384] nas: dbBeginTransaction tlogRun, OK - rc:0
Jul  1 22:15:37:025 [11384] nas: dbCommitTransaction tlogRun, OK - rc:0
Jul  1 22:15:37:196 [10212] nas: (ao_status) from ***/51948
Jul  1 22:15:37:947 [5320] nas: Subscriber processed 1 msg.,1 updates the last 10s, 0.10 msg/s, queued:1
Jul  1 22:15:38:845 [7644] nas: ptNetIpToHost - getaddrinfo failed for 92729086
Jul  1 22:15:38:845 [7644] nas: nsLookup ip:92729086 => '92729086' in 2250ms
Jul  1 22:15:38:851 [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:38:857 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:38:857 [5840] nas: dbsRun committed 1 requests. 0 remaining in queue...
Jul  1 22:15:40:536 [13288] nas: COM Error [0x80040e31] IDispatch error #3121 - [Microsoft OLE DB Provider for SQL Server] Query timeout expired
Jul  1 22:15:40:536 [13288] nas: NiS-Bridge: Transaction-log XXXistration, failed to remove transaction entries older than 365 days.
Jul  1 22:15:41:095 [7644] nas: ptNetIpToHost - getaddrinfo failed for ***7
Jul  1 22:15:41:095 [7644] nas: nsLookup ip:***7 => '***7' in 2250ms
Jul  1 22:15:41:095 [7644] nas: ptNetIpToHost - getaddrinfo failed for ***7.***.com
Jul  1 22:15:41:095 [7644] nas: nsLookup ip:***7.***.com => '***7.***.com' in 0ms
Jul  1 22:15:4*** [5840] nas: dbBeginTransaction dbsRun, OK - rc:0
Jul  1 22:15:41:108 [5840] nas: dbCommitTransaction dbsRun, OK - rc:0
Jul  1 22:15:41:108 [5840] nas: dbsRun committed 2 requests. 0 remaining in queue...

 

 

Controller log indicate stopped on Jul  1 22:14:53:559
Jul  1 22:14:52:994 [1408] Controller: (async)cb_hub_acallback done
Jul  1 22:14:52:995 [1408] Controller: RREQUEST: _close <-***/50607  h=296 d=0
Jul  1 22:14:53:559 [1408] Controller: Process stopped (probe=alarm_enrichment, pid=4100)
Jul  1 22:14:53:573 [1408] Controller: probeGenerateMagicKey for alarm_enrichment
Jul  1 22:14:53:573 [1408] Controller: probeFindCRCs for alarm_enrichment
Jul  1 22:14:53:843 [1408] Controller: probeFindCRCs - 0
Jul  1 22:14:53:843 [1408] Controller: probeGenerateMagicKey - LL0P0tM9FJtztfSmSrctGJvBeS9npPNUHUNlOKZpHU7UYiSOwCVgJvJm1KNUHmOq20dlM10GQ9a98LRJ8zTnUw==
Jul  1 22:14:53:843 [1408] Controller: reserve_port (alarm_enrichment) starting at 48000
Jul  1 22:14:53:843 [1408] Controller: sockGetFreePortStartingFrom: 48007: using fam=2 strict=0
Jul  1 22:14:53:844 [1408] Controller: sockGetFreePortStartingFrom: 48022: using fam=2 strict=0
Jul  1 22:14:53:845 [1408] Controller: reserve_port (alarm_enrichment) - assigned to 48023
Jul  1 22:14:53:845 [1408] Controller: _ProcStart - Startup command for alarm_enrichment: ../../../../$NIM_JRE_HOME/bin/java.exe
Jul  1 22:14:53:845 [1408] Controller: MyStringExpand (../../../../$NIM_JRE_HOME/bin/java.exe)...
Jul  1 22:14:53:845 [1408] Controller: MyStringExpand - expanded to ../../../../jre/jre7/bin/java.exe
Jul  1 22:14:53:845 [1408] Controller: MyStringExpand (-Xms2048m -Xmx3072m)...
Jul  1 22:14:53:845 [1408] Controller: MyStringExpand (-Dfile.encoding=UTF-8 -jar ../lib/alarm_enrichment.jar)...
Jul  1 22:14:53:845 [1408] Controller: _ProcStart - path = C:\Program Files (x86)\Nimsoft\probes\service\nas\alarm_enrichment\../../../../jre/jre7/bin/java.exe
Jul  1 22:14:53:845 [1408] Controller: _ProcStart - command line = ../../../../jre/jre7/bin/java.exe -Xms2048m -Xmx3072m -Dfile.encoding=UTF-8 -jar ../lib/alarm_enrichment.jar
Jul  1 22:14:53:848 [1408] Controller: Probe 'alarm_enrichment' started (pid=6344) (restart 1)

Outcomes