E9.0 Subsystem processing time

JohnDanter2

JohnDanter2

Reputable Poster
Hi all

I have a subsystem that kicks off to process TMS data
In the Initialise section I get UTC time, in the end on a Level Break footer on SHPN I get UTC again and write the start and end times to an audit table.

I am seeing the time difference often be 1 - 2 seconds, so it's pretty quick. But even though the version is set to Wait every 500ms the records in my audit are always 10 seconds apart!!!
22/12/20 10:26:57 (UTC)22/12/20 10:26:57 (UTC)
22/12/20 10:27:09 (UTC)22/12/20 10:27:10 (UTC)
22/12/20 10:27:22 (UTC)22/12/20 10:27:22 (UTC)
22/12/20 10:27:34 (UTC)22/12/20 10:27:34 (UTC)
22/12/20 10:27:46 (UTC)22/12/20 10:27:47 (UTC)
22/12/20 10:27:59 (UTC)22/12/20 10:27:59 (UTC)
22/12/20 10:44:13 (UTC)22/12/20 10:44:16 (UTC)
22/12/20 10:46:46 (UTC)22/12/20 10:46:47 (UTC)
22/12/20 12:16:22 (UTC)22/12/20 12:16:23 (UTC)
22/12/20 12:31:10 (UTC)22/12/20 12:31:11 (UTC)
22/12/20 12:32:01 (UTC)22/12/20 12:32:02 (UTC)
22/12/20 12:37:03 (UTC)22/12/20 12:37:04 (UTC)
22/12/20 12:42:17 (UTC)22/12/20 12:42:18 (UTC)
22/12/20 12:42:43 (UTC)22/12/20 12:42:44 (UTC)
So what is my subsystem doing for 10 seconds? As there was a massive list of W records on F986113
It was my understanding that subsystems don't need to GET the specs from the server like UBES do before they start processing, as they are a subsystem. Am I wrong there?

I can't explain the throughput to my manager on why the gaps are always 10 seconds.

Thanks

John
 

JEMILLER

VIP Member
A subsystem job is just essentially a UBE that runs in a loop with each iteration pulling its report interconnect variables and other parms from the F986113. There should be no more than a small latency between the last iteration (job) completing and the next waiting one starting.

I think your best bet is to enable debugging on the subsystem job and see what it is doing for those 10 seconds. While the job (runube) process will not have to spawn each time a subsystem job runs, all the section logic will execute and not just the one you have instrumented with start and end times.
 
johndanter

johndanter

Legendary Poster
Thanks.
Yeah, that's why I chose a subsystem Vs a coded launch of a UBE to process the shipment.
The start time is in the init section and the end time in the lvl bk footer on shpn.

So there shouldn't be too much else this subsystem is doing.

Strangely looking back at the timings, it did used to be 3 seconds!
Which IS 1 second processing 2 seconds wait.

So I'm not sure what's changed. Definitely not the code :(
 
JohnDanter2

JohnDanter2

Reputable Poster
The answer to this

If you forgot to switch the Suppress UBE Output tick box in the main UBE menu (for the subsystem UBEVERS), each time the SBS ends it overwrites it's PDF in the print queue.
Switching this off removes the time the UBE spends after it's finished processing
 
Last edited:

KarumuriN

Member
Thanks.
Yeah, that's why I chose a subsystem Vs a coded launch of a UBE to process the shipment.
The start time is in the init section and the end time in the lvl bk footer on shpn.

So there shouldn't be too much else this subsystem is doing.

Strangely looking back at the timings, it did used to be 3 seconds!
Which IS 1 second processing 2 seconds wait.

So I'm not sure what's changed. Definitely not the code :(
Hi have seen your post on B91300C launch batch application with logging turned on. Were you able to achieve logs on server with this business function?
 
JohnDanter2

JohnDanter2

Reputable Poster
I don't think so no.
Easier to ask CNC to log the krnl or launch it manually with logging on
 
kiran4hari

kiran4hari

Well Known Member
Hi all

I have a subsystem that kicks off to process TMS data
In the Initialise section I get UTC time, in the end on a Level Break footer on SHPN I get UTC again and write the start and end times to an audit table.

I am seeing the time difference often be 1 - 2 seconds, so it's pretty quick. But even though the version is set to Wait every 500ms the records in my audit are always 10 seconds apart!!!

It was my understanding that subsystems don't need to GET the specs from the server like UBES do before they start processing, as they are a subsystem. Am I wrong there?So what is my subsystem doing for 10 seconds? As there was a massive list of W records on F986113

I can't explain the throughput to my manager on why the gaps are always 10 seconds.

Thanks

John
We have also created a custom subsystem so that the UBE doesn't try to GET the specs every time. But we are seeing too many files open error messages after the Subsystem runs for few hours. Not sure why it is trying to open dddict.ddb so man times.

Have you observed these kind of issues in your subsystem?

TAMInitX (/PY900/specfile/dddict.xdb): Error opening data file "/PY900/specfile/dddict.ddb" : Std C errno=3452 : Too many open files for this process.
 
JohnDanter2

JohnDanter2

Reputable Poster
Hi

I've not seen this, but it should only get specs once??? You may see memory leaks with bad table IO not wrapped in Open Close, but I'm confused as to why your SBS is still getting specs after it was run the first time?
 
kiran4hari

kiran4hari

Well Known Member
Hi

I've not seen this, but it should only get specs once??? You may see memory leaks with bad table IO not wrapped in Open Close, but I'm confused as to why your SBS is still getting specs after it was run the first time?
We are calling a custom bsfn to insert a record to F986113 in the end section. Looks like that API might be opening RDA spec for every call. We see following errors

4435 Tue May 17 12:15:08.930568 SpecOpen.c1288
openRemoteTAM() - Failed to open the TAM file /PY900/specfile/UBEOverride/1158839/rdaspec.ddb using the API TAMInitY. TAM flag word = 0.

4435 Tue May 17 12:15:08.931152 SpecOpen.c2633
jdeSpecOpenLocal completed in error - JDESPECRESULT_FAILED.

4435 Tue May 17 12:15:08.931208 k2subsys.c349
--UBE--SS: ubeReport_AddSubsystemRecord() can't open RDASpec

4435 Tue May 17 12:15:09.190744 jdetama.c650
JDESPEC0000027 - TAM init failed!

4435 Tue May 17 12:15:09.190848 SpecOpen.c2633
jdeSpecOpenLocal completed in error - JDESPECRESULT_FAILED.

4435 Tue May 17 12:15:09.438664 jdetama.c650
JDESPEC0000027 - TAM init failed!

4435 Tue May 17 12:15:09.438768 SpecOpen.c2633
jdeSpecOpenLocal completed in error - JDESPECRESULT_FAILED.

4435 Tue May 17 12:15:09.699912 jdetamsp.c3236
Error creating DDDICT.XDB

4435 Tue May 17 12:15:09.702136 jdetama.c650
JDESPEC0000027 - TAM init failed!

4435 Tue May 17 12:15:09.702184 SpecOpen.c2633
jdeSpecOpenLocal completed in error - JDESPECRESULT_FAILED.

4435 Tue May 17 12:15:09.703568 jdetama.c650
JDESPEC0000027 - TAM init failed!

4435 Tue May 17 12:15:09.703608 SpecOpen.c2633
jdeSpecOpenLocal completed in error - JDESPECRESULT_FAILED.
 
JohnDanter2

JohnDanter2

Reputable Poster
So you are not seeing errors in your subsystem processing. You are seeing errors in the process that wakes the subsystem up? That's totally different and not related to SS processing really
They also look like local FAT client errors....? Maybe check in all your related work, delete the 6 DDDCIT type files DDDICT, DDTEXT and GLBTBL, get all your objects again and try again

You are de-railing this thread with a non related question :)
 
Top