Automic Workload Automation

Hallo zusammen,

alle Admins im Urlaub und wer ist anwesend? Ich  :/

Aber vielleicht kennt ja jemand dieses Verhalten? Version ist 11.2.2+build.627

"ORA-00001: Unique Constraint (UC4.PK_EV) verletzt" INSERT INTO EV (EV_AH_Idnr, EV_VName, EV_Value, EV_Source, EV_SortOrder, EV_ERTUsage) VALUES (:A0001, :A0002, :A0003, :A0004, :A0005, :A0006)

Die Fehlermeldung kommt bis zu 3 mal pro Sekunde!

Vorab vielen Dank und Grüße aus Nürnberg
Manfred

Das kann verschiedene Ursachen haben, hier wären ein paar mehr Zeilen vom LOG hilfreich.

....und ein Anruf bei der DB Admin Bereitschaft....

Danke Wolfgang, irgendwie hab ichs geahnt und die Meldung ist im Übrigen von unserem DB Admin@home. Da es hier um die QSU geht, bin ich aber gewillt, das Thema aufs nächste Jahr zu verschieben.

Bitte.

Entweder Du postest ein bisschen mehr, dann kann ich schauen, ob ich daraus was erkennen kann, oder Du machst ein ticket beim Support auf (inkl. der Logs) zur Analyse.

Hab bereits einen größeren Auschnitt des Logs angefordert und häng ihn hier mal ran, sobald ich ihn habe. Selber kann ich leider nicht darauf zugreifen, da bin ich auf uarbeit angewiesen.
Danke!

Hallo Manfred,

Wie FrankMuffke schon geschrieben hat lässt sich aus der einen Zeile nicht viel herausholen, anhand der Tabelle auf die hierbei referenziert wird (EV) sehe ich lediglich dass irgendeine Objektvariable (Variables&Prompts) im Zugriff auf die DB hängt. Ohne Zwangstrace oder wenigstens dem Automation Engine Log (\temp Verzeichnis der Automation Engine) lässt sich aber nicht viel sagen.

Dass hier kein Missverständnis aufkommt, die DB Logs brauchen wir im Automic Support nicht, uns sind die Automation Engine Logs wichtig, vielleicht haben Sie darauf Zugriff?)

Da der Fehler aber von einer Objektvariable triggert, muss ein Objekt das sich zur Zeit im Aktivitätenfenster befindet der Auslöser sein, vielleicht befindet sich ja ein aktiviertes Objekt in einem "verdächtigen" Zustand, das könnten Sie noch prüfen

Hallo Harald,
Danke für die Infos, da kann ich jetzt zumindest selber noch etwas forschen. Das Ticket liegt aktuell beim Provider, ich werde das gleich noch entsprechend dokumentieren, damit ich die richtigen Logs bekomme. Ich selbst habe da leider (noch) keinen direkten Zugriff darauf.

Ok, ein anderer Betriebs-Kollege kümmert sich jetzt gleich um die Bereinigung des Aktivitätenfensters, es hängt tatsächlich ein Job mit "ENDED_LOST - undefiniert beendet (Agent vorzeitig beendet)". Er hegte aber auch den Verdacht, dass es sich möglicherweise um eine Nagios-Abfrage handelt. Im Sekundentakt? Na gut, wir werden sehen, was sich tut. Oder nicht tut.

Der ENDED_LOST-Kandidat wars schon mal nicht. Hätte jetzt noch einen, der auf eine externe Abhängigkeit wartet. Auftrag ist wieder mal raus, wir dürfen ab QSU eben leider nur lesend zugreifen. Das kann jetzt wieder mal dauern.....
Parallel dazu werde ich auch die Nagios-Spur verfolgen, wie hier die Überwachung aufgesetzt ist.

Nochmals vielen Dank für die Unterstützung hier! Sobald ich Ergebnisse habe, werde ich diese natürlich kommentieren.

Vermutlich haben wir die Ursache beheben können, der Tip mit dem Aktivitätenfenster hat uns auf die richtige Fährte geführt. Ein "unwichtiger" Mandant hatte ~8000 wartende API-Calls im selbigen! Wir nutzen die API-Schnittstelle bei Changes zum automatischen Stoppen und Starten der Tasks und das wurde nun bereinigt. Warum das nun genau bei diesem Mandanten offensichtlich nicht mehr funktioniert, das ist dann noch zu klären. Meine Log-Anfrage wurde leider völlig ignoriert, aber ich bin mir ziemlich sicher, dass das Phänomen darauf zurückzuführen ist.

ob die 8000 CallAPI Aufrufe tatsächlich der Auslöser sein können, kann ich nicht bestätigen oder abstreiten, wenn diese Aufrufe, oder deren Aktivierungen Objektvariablen verwenden dann könnte es schon sein. Es ist schwierig im "Blindflug" ohne Logfiles zu analysieren daher kann ich nur mutmaßen. Wenn aber die Meldungen durch das entfernen dieser Aktivitäten verschwinden, würde der Erfolg aber recht geben :)

Jedenfalls sind diese DB Meldungen nicht unbedingt mit CallAPI Aufrufen in Verbindung zu bringen.

Guten Morgen Harald, Sie haben in allen Punkten recht. Meine Hoffnung hat sich nicht bestätigt, die letzte Nachricht von 19 Uhr brachte leider keine Besserung. Ich werde nun etwas Druck zu machen, um die Logs im Laufe des Tage doch noch zu kriegen.

Hallo Harald,

jetzt hab ich was bekommen. Wie bringe ich denn die 10 MB am besten zu Euch? Hab mal versucht, etwas auffälliges zu finden, das einzige was mir auffiel, das CPsrc_log ist proppevoll mit diesen Meldungen und würde taktmäßig durchaus zu den Fehlermeldungen passen:

20161222/221116.035 - U00003406 Client connection '1153394(22)'  from '10.20.20.202:55891' has logged on to the Server.
20161222/221116.037 - U00003407 Client connection '1153394(21)' from '10.20.20.202:55891' has logged off from the Server.
20161222/221118.315 - U00003406 Client connection '1153395(22)'  from '10.30.3.112:37888' has logged on to the Server.
20161222/221118.323 - U00003407 Client connection '1153395(21)' from '10.30.3.112:37888' has logged off from the Server.
20161222/221119.053 - U00003406 Client connection '1153396(22)'  from '10.30.3.112:37892' has logged on to the Server.
20161222/221119.064 - U00003407 Client connection '1153396(21)' from '10.30.3.112:37892' has logged off from the Server.
20161222/221119.961 - U00003406 Client connection '1153397(22)'  from '10.30.3.112:37896' has logged on to the Server.
20161222/221119.971 - U00003407 Client connection '1153397(21)' from '10.30.3.112:37896' has logged off from the Server.
20161222/221120.320 - U00003406 Client connection '1153398(22)'  from '10.30.3.112:37901' has logged on to the Server.
20161222/221120.335 - U00003407 Client connection '1153398(21)' from '10.30.3.112:37901' has logged off from the Server.

Hatte versucht einen Incident anzulegen, finde dazu nur leider keine Upload-Funktion....

Manfred

Ich habs geschafft :) Ticket ist INC00127706

Guten Morgen

sobal der INC angelegt UND gespeichert ist, erscheint ein Upload Button....

https://us.v-cdn.net/5019921/uploads/editor/tc/lqt6q404g0gu.jpg" width="117">

Die Zeitabstände von ca. einer Zehntelsekunde könnten schon von der CALl API stammen...

Anhand der IP Adresse können Sie eventuell noch was rausfinden.

Hallo Herr Mauermann,

ist jetzt teilweise out of context, aber die Meldungen des CPs:


20161222/221116.035 - U00003406 Client connection '1153394(22)'  from '10.20.20.202:55891' has logged on to the Server.

sind nicht relevant, der CP macht den lieben langen Tag nichts anderes als Verbindungen zu verwalten, da sind die Meldungen von An- und Abmeldungen normal, speziell wenn Sie viele CallAPI Aufrufe haben.

Den Incident hab ich übernommen, sehe mir das an.

Super, Danke vorab!

So, um 14 Uhr ist Showdown, wie von Harald_Heidinger_152 vorgeschlagen, werden wir die Prozesse beenden, dabei die Meldungsentwicklung beobachten, ggfs. Prozesse eruieren sowie killen und danach neu starten.
Wir sind gespannt  B)
FrankMuffke : IP-Adressen hatte ich noch geprüft, die waren aber völlig normal. Vereinzelte Abweichler konnte ich dem Monitoring zuordnen, d.h. auch hier war alles sauber.

Hmm ja, kurzzeitiger Erfolg war sichtbar, jetzt kommen die Meldungen trotzdem wieder. So ca. 15 Minuten nach dem Neustart war wohl Pause. Allerdings haben die Kollegen keinen Kalt- sondern einen Warmstart durchgeführt, wie ich dem Meldungsprotokoll entnehmen konnte. Jetzt mach ich erstmal einen Break und bespreche mich morgen mit den Kollegen und versuche zu klären, warum man das jetzt genau so machen musste.
Danke für Eure Hilfe und Geduld!

Update:

• Kaltstart ist für kommenden Montag beauftragt
• Es laufen derzeit Messungen, welche Tabellen überdimensional wachsen, unser Provider sieht hier nur den gesamten Tablespace
  

Irgendwie hat es den leichten Anschein, dass die ORA-00001 Meldungen zwar ursächlich von UC4 kommen, aber nicht unbedingt etwas mit dem Zuwachs zu tun haben müssen.

Noch mal ein abschließendes Update, nach Reorg, Kaltstart und phys. Defragmentierung:

• Entw.    ca. 30 GB,
• QSU      ca. 130 GB
• PROD  ca. 90 GB

Aussage unserer DB-Admins:
Die Statistik zeigt nach der DB-Defragmentierung kein Wachstum vom CLOB der Tabelle RT, dazu  allerdings  "normales" gesamtes Wachstum des Tablespaces (durchschnittlich 75 MB pro Tag seit letzten 8 Tagen und 187 MB pro Tag seit DB-Defragmentierung am 10.01)  - entspricht dem Wachstum in PRODUKTION - 192 MB pro Tag seit 29.12.2016.
Obwohl wirkliche Ursache des Problems ungeklärt bleibt, der Stand hat sich nach dem Reboot des uc4-Servers und DB-Defragmentierung wieder normalisiert. Ich sehe hier keine weitere todo's auf DB-Ebene.
Die vorgeschlagene SQL-Abfrage um  Große der Reports pro Mandant zu ermitteln, ist leider zu teuer und nicht ausführbar -  nicht genug Platz in TEMP ....

Unser Provider hat erfreulicherweise das im letzten Kommentar verlinkte SQL ausführen können (10 Min., 20GB Temp-Tablespace) und wir haben eine Spur:

Auszug aus dem Ergebnis:


Der Kollege, der unsere Daten-Austausch-Plattform betreut ist nun restlos bedient, weil er nur den 2. Platz belegt. Da scheint unsere "Schatten-IT" zugeschlagen zu haben, wir haben zwar keinen zeitlichen Größenverlauf, aber die Zahlen sprechen für sich.

Die Abfrage ist jedenfalls super, an dieser Stelle nochmals Dank an den Automic-Kollegen Andreas_Sprosec_7439