Hi Jack,

On my search for recurrent messages in ashlog I found this one:

08-Fev-20 08:17:31 [UZLENOVO:efc-2]<MAIN:f4f5> Your job control block (jobtbl.sys) has been zapped - exit A-Shell now!
08-Fev-20 08:17:31 [UZLENOVO:efc-2]<MAIN:f4f5> [Expected: job 2 (UZLENOVO:efc); was: 2 ()]
08-Fev-20 08:17:31 [UZLENOVO:efc-2]<MAIN:f4f5> jcbrebuild #5
08-Fev-20 08:17:31 [UZLENOVO:efc-2]<MAIN:f4f5> 08-Fev-20 08:17:31 [TSKAAB,2,MAIN,suporte,UZLENOVO:efc,totjobs=28] License recount(5)
Was: 8P/17L, Is: 9P/17L (free passes: 6 tty, 2 ip), GrpUsg:0,0,0

08-Fev-20 08:17:31 [UZLENOVO:efc-2]<MAIN:f4f5> Trigger: JCB record zapped by
08-Fev-20 08:17:31 [UZLENOVO:efc-2]<MAIN:f4f5> device:, user:suporte, job #2


In fact, I didn't found it, it happened while I was testing something in a customer but, here and there, it happens and the screen get a lot of scarry messages "your jobcontrol has been zapped" and users think they are under attack.
But what caught my attention was the second message: [Expected: job 2 (UZLENOVO:efc); was: 2 ()]
Why does A-Shell was expecting for "job 2" ?

Is there any way to prevent this or popup a more friendly message?

Thank you

Here's the background...

On launch, each instance of A-Shell/Windows calculates it's identifier, which can be made in various ways depending on the environment, but usually consists of a machine identifier (UZLENOVO in the above case) followed by a colon and unique suffix (to differentiate multiple instances launched from the same machine). In the typical P2P case, the suffix will be :01, :02, etc. based on the number of instances already running, which A-Shell can "see" in the local memory. In the RDP case, Windows sandboxes each instance, preventing it from "seeing" other instances, so we can't just count them. Instead it appends some kind of derived memory location as to hopefully make it unique. But that method started to break down in newer versions of Windows server in which the apparent environment of each instance is so similar that we end up with the same "unique" identifier as other instances, which then leads to the problem you see above.

[UZLENOVO:efc-2] indicates JOB2, with instance identifer UZLENOVO:efc. If you look carefully back in the log, I'm guessing you'll see two launch messages for [UZLENOVO:efc-2], one of which indicates that the identifier was already in use. When A-Shell sees that there is already a JOBTBL record with the same instance identifer as the new instance being launched, it concludes that the old JOBTBL record was abandoned by a session that crashed without exiting cleanly. To avoid accumulating such records, it reuses them. So you have two instances sharing the same JOBTBL record. For a short time, they may coexist, not realizing that they are cohabitating with their doppelganger. But when one exits, it clears itself from the JOBTBL, and shortly after that, the other one will notice that suddenly the apartment has been cleared out and a For Rent sign posted on the door. That's when you get the message [Expected: job 2 (UZLENOVO:efc); was 2 ()], meaning that it expected to find its JOBTBL record containing the nametag UZLENOVO:efc but instead found it blank.

The most direct solution for this is to add the -ntts switch to the A-Shell launch command. That changes the way the unique instance identifier is calculated such that each instance will definitely get a unique identifier. The only downside is that we can no longer identify which instances belong to the same workstation, and thus each instance will count against the license. (In the normal case, all of the instances originating from the same workstation can share a license.)

It's possible that there may be a better technological solution, but the amount of logic which has accumulated over the years to address this issue, solely for the purpose of allowing multiple instances to share a license, has overwhelmed all cost/benefit analyses (at least from our perspective, where the cost keeps getting higher while the benefit remains negative, i.e. fewer licenses sold). The dealer/customer perspective might be somewhat different. That said, you're welcome to bring your case to the A-Shell Senate where it will be duly, fairly, and objectively considered. (Or not.)

Hello Jack,
Thank you for the detailed and clear explanation, it makes sense in my current scenario where almost all my customers (the goal is to remove the "almost") run A-Shell in RDP session to access the datacenter.
I don't want to ask for new variantions of the A-Shell licensing and I want to respect its rules.
My problem is that I'm getting a lot of those messages in the ashlog file and, worst, not rarely, corrupted jobtbl occurrencies.
So, my question is, does "-ntts" will prevent jobtbl corruption?
Because, as far as I understood, the messages will disappear.

As for the downside to lose track about which instances belong to which workstation, by now, that's secondary,

Thank you very much

Hi Jack,
Apologize but, I'm back to this topic

It's early in the weekend so, the perfect moment to try the NTTS switch, before go to the street party play the Brazilian Carnival
I decided to take a look in the documentation with the hope to find a way to activate NTTS via MIAME instead of adjust all the shortcuts with the -ntts switch and, there it was: OPTIONS=NTTS, fantastic

I had started to delete the ashlog before activate NTTS and logged in A-Shell.

15-Fev-20 09:35:58 [UZLENOVO:198-0]<:0> jcbrebuild #0

I was surprised to see the above message but, ok, let's see what happens with NTTS and turned it on.


15-Fev-20 09:37:46 [suporte-52EA8A:1-0]<:0> jcbrebuild #0
15-Fev-20 09:39:00 [manuela.goncalves-5-0]<:0> jcbrebuild #0
15-Fev-20 09:39:00 [manuela.goncalves-5-0]<:0> 15-Fev-20 09:39:00 [,0,,manuela.goncalves,manuela.goncalves-5,totjobs=102] License recount(0)
Was: 3P/5L, Is: 1P/5L (free passes: 2 tty, 2 ip), GrpUsg:0,0,0

15-Fev-20 09:40:00 [manuela.goncalves-6-0]<:0> jcbrebuild #0
15-Fev-20 09:41:24 [suporte-44C442:1-0]<:0> jcbrebuild #0
15-Fev-20 09:41:24 [suporte-44C442:1-0]<:0> 15-Fev-20 09:41:24 [,0,,suporte,suporte-44C442:1,totjobs=102] License recount(0)
Was: 1P/4L, Is: 2P/4L (free passes: 0 tty, 2 ip), GrpUsg:0,0,0

15-Fev-20 09:55:03 [Cristina.Ramos-3FF7-0]<:0> jcbrebuild #0


Above are the sequence of logs for three RDP sesssions with different users.
Starting with the job nomenclature change, I prefer the NTTS method that identifies the RDP user.
It seems there is a limit for the username that is filled with an unique ID until complete some maximum size, is it?
But while manuela.goncalves and cristina.ramos truncate on 19 characters, suporte doesn't what leads me to think that the ID has a maximum structure of xxxxxx:x.
If my assumption is correct, what will happen if the username has more than 19 characters?
Apologize, I could have tried it

Regarding the logs, here are my doubts:
1. It is supposed that each A-Shell login adds a new record to ashlog?
2. In the above excerpt of the ashlog, the user "suporte" opened several (4) consecutive and concurrent A-Shell sessions but only one log (the first one)
In the session of "manuela.goncalves" I've opened 2 sessions but got the next two logs.
Is the any reason for the different behaviour?
3. What does "License recount(0)" means, it's just informative and the recount didn't take place or it did recount but without find any lost jobs?
4. If the above messages are all informative and wasn't triggered by any problem, wouldn't it be plausible to consider a different log for such kind of messages?

Anyway, no hurry, besides the doubts, I'm going to keep this first customer with NTTS to check if the zapped jobs go away.

thank you and have a nice weekend

Hi Jorge,

It is well known that you are most productive when working in a boisterous environment like a sports bar, but hopefully you you've drawn the line at Carnival and won't see this until the city has gone quiet again.

To start with the most important issue: you're absolutely right that there is a limit of 19 characters on the session identifier name, which absolutely would be a problem for user names that are close to that length without the -xxxxx suffix. In fact, it is a problem for manuela.goncalves, leaving room for only 1 digit of the suffix. (Note that the -0 on the end of that is the job #, which will be -0 initially until it is established.) So it is quite likely that if there are multiple sessions for that user, they may end up with the same identifier and clobber each other. The format has evolved over many generations of Windows environments, but the length was stuck at 20 (including a null byte) due to reluctance to revise the JOBTBL.SYS format (which would create an obstacle for updates). In the standard form, we use the machine id (which is limited to 15 characters) rather than the user name, so the 19 is sufficient. But in the NTTS case we use user names, which could be much longer. It may be time to stop postponing the expansion of the JOBTBL and just get it over with. But that will take some time to think through, so for the immediate need, I think I need to truncate the user name before adding the suffix. (That will be 1676.3+, to be posted sometime later today.)

On your other questions:

1. If TRACE=INOUT, then yes, each session should get at least two entries in the ashlog on startup, and at least one on exit, which look something like this:

(In the case of ATE there will also be an ATE identification line. Either way, there may be additional lines depending on other options and conditions.)

2. Something is wrong if you aren't getting those entries, but are you sure you have the TRACE=INOUT directive in the miame.ini?

3. The "jcbrebuild(x)" and "license recount" messages are normal (perhaps excessive). The concept is that because we got bullied(?) into allowing multiple sessions for the same workstation to share a single license, we couldn't simple add one for each new session and subtract one for each terminated session. For example, if on my workstation I launch 2 sessions, the first one will use up a license (shown as [P] in the "In: Nodes=" trace, but the second one will not count (shown as [L]). But if that first job exits first, then the remaining job, which previously was not using up a license, will have to take over the license that was previously charged to the first job. The process of making these calculations results in the "jcbrebuild()" and "license recount" traces.

4. This question suggests that you expect all of the messages in the ashlog to be "problems". Actually, most are not problems but are just information useful for monitoring the system. In retrospect it may have been a good idea to insert a message category identifier at the start of each message. (In the UNIX world, typical log levels are DEBUG, INFO, WARN, ERROR, FATAL.) You could then easily filter for certain categories of messages, as well as configure the system to only display messages of a certain severity of higher. (Level=DEBUG logs all, Level=ERROR logs only ERROR and FATAL, etc.). The problem with implementing that system now is that it would require going through all of the existing TRACE options and categorize them, not to mention all of the trace messages which are triggered by events not related to the TRACE options. It might actually be worth it though, particularly given your new year's resolution to analyze every message in the log file!

Until then, keep dancing!

When you get done dancing, I suggest you install this update to fix the issue with long user names:

ash-6.5.1676.3-w32c-upd.zip
ash65notes.txt

Hi Jack,
Not much dance and zero alchool due my preparation for the Marathon, in patticular, the 20Km training, later today when the 35º go much lower.
But it was fun to watch Violeta enjoying the ambiance

So, today, before going to melt outsider, i have work to get done and your update is much appreciated, it's already in place and confirmed the truncation.
Anyway, this means that I still have to control the usernames length becuse something like manuela.goncalves01 and manuela.goncalves02 will still be a problem, correct?
This is not a problem.

Thank you very much.

PS: By the end of the day, I guess, will have a couple of messages to analyze under this topic

Bravo to you - I wish I was in shape for a 20k!

But just to clarify one point: there's no problem for A-Shell with names that are the same up to the point where they get truncated like in your example. A-Shell (as of 6.5.1676.3) will shorten any long names as needed to make room for the unique suffix. It's possible that two long names that are the same up to the point of truncation will look like the same user when seen in SYSTAT/C, but A-Shell will still be able to distinguish them by the suffix.

Hi Jack,
I had to remove the NTTS in the customer because, if it was not just a coincidence, in their first day using NTTS, A-Shell hanged because there were a lot of sessions opened in the Task Manager and ashlog was full of ZAPed jobs.
Just to clarify the scenario:
1. A-Shell run in a remote VM (Windows Server 2012) where all users access via RDP
2. There is also an web portal (configured in IIS) that calls A-Shell
3. In my software, each option the user selects from the menu launches a new instance of A-Shell

So, this is an environment with very heavy calls to A-Shell instances and there are always several sessions running at the same time on the same machine, as well as a lot of consecutive open/close of those instances.

Any suggestion about the next steps?

The easiest next step would be to examine the ashlog file. If you want to email it to me, I suspect it will give an indication of the problem.

Presumably the problem is related to the session ID's not being unique, but should be clear in the long. I don't think it is a licensing issue. But just to clarify:

1. The RDP users are all going to count against the license (which is normal in any case)
2. The web (-cgi) users are also going to count against the license, but they are connected for such a short time, a lot of connections can probably share a small number of licenses.
3. The instances launched by A-Shell will not count against the license (regardless of NTTS)

Hi Jack,
email sent and, to register here the follow-up

1. sure, every user who access the system has their own login and, adding the CGI user, are fewer than the A-Shell License
2. all web connections use the same user and besides the duration is short (only the time to execute the query) surely, there are concurrent sessions opened at the same time by different physical persons using the same user
3. due the logic behind my platform, most of the time each user has, at least, two A-Shell sessions opened (one for the main menu and some option) but, not rarely they have more or much more

Thank you very much

Looking at your log file, there's clearly something amiss, but it's difficult to be sure just what it is without the TRACE=INOUT option set. I'm guessing you turned it off because it seems too verbose in a situation like yours where there are many many launches (every menu selection and every web access). But, maybe you can turn it on for an hour or so just to capture a sample. (Of course without the NTTS-related problem showing up, it won't be as useful, but it would still be a useful baseline reference.)

But let's go over one error sequence from your log. You'll see a lot of references to "jcbrebuild #" which are mostly normal, but note the following:

jcbrebuild #0 is the normal/initial rebuild in set_instance (but no more often than once per minute)...
jcbrebuild #2 is a normal rebuild in qpurge (if unsure whether the job being removed was using a license node or not) ...
jcbrebuild #4 occurs on program launch if we detect or jobtbl was overwritten...

Because you don't apparently don't have the TRACE=INOUT set, we can't see when new jobs are launched, except when we see jcbrebuild #0 (which will be no more than once per minute). But in most cases, we'll see an indication of the job termination (both the jcbrebuild #2 message and the License recount ... Was: #P/#L, Is: #P/#L message).

to the following starts out with job 2 (SERVERICO$-2358:1) terminating at 13:33. Then at 15:54, we see a new launch for SERVERICO$-22A0:1. Immediately we see a jcbrebuild #4 message for job 2 (SERVERICO$-2282:1), which indicates that it has detected an overwrite of its jobtbl record while loading a RUN file. Since Job 2 is the same job that was freed up a couple minutes earlier, we can assume that SERVERICO$-2282:1 must have after the previous job 2 was freed, but within a minute of the prior new session launch (due to lack of jcbrebuild #0 message).

Then we get the inevitable "zapped" message, which indicates that session SERVERICO$-2282:1 (job 2), which presumably launched within the last 2 minutes, now sees that it's jobtbl record has been overwritten by SERVERICO$-22A0:1 (which just launched). So far, I don't have an explanation for why that happened. (Timing/lock synchronization issue? Logic error?) If it's purely a timing/lock synchronization problem, it isn't clear why it would be more likely to occur with in the NTTS mode, which you seem to be indicating.

The remainder of the log excerpt shows the overwritten job 2 getting itself into a kind of infinite loop due to failure to exit cleanly on the error #35. You'll have to look at your SBXISA.LSX file to see what happens at b54 when the error is trapped and whether you could do anything more cleanly. (I'm guessing that SBXISA.SBX ends, which means it returns to the caller SOFWEB, which doesn't realize there was an error, and so it then proceeds to call SBXMSG which then gets the error again, and we go back around.)

Suggestion: when an error occurs within an SBX that is serious enough to abort the caller, you can use ASFLAG.SBR with either the AF_EXITSBX or AF_SETCTRLC flag to either force an abort or send an abort signal to the caller. Obviously the goal is to avoid such a situation in the first place, but it might be worth a small effort to try to crash more gracefully.

Thanks Jack for the thorough analysis, including the error 35, which I should have removed from that (old) ashlog because I haved solved it in the meantime.
In fact, that's why I've elected 2020 to analyse all messages in ashlog, to trap such kind of silent problems that summed up can cause unstable environments and sudden crashes w/o apparent explanations.

I will take one day to activate the NTTS, as well as the INOUT trace, in this customer that will know about the testing environment in case something goes wrong and the system hangs.
Anyway, that will be only somewhere in March because, I will be out next week in places with very poor internet signal so, w/o guarantee to act in some emergency but, no rush.
I really want to understand all the eventual problems caused by my login logic to jobtbl and, do whatever needed to fix and stabilize it.

I'll let you know about that lab day.
Thank you very much

Hi Jack,

Recovering this topic ...

Should I worry to find out what is behind these warnings?
I foung several of them in different xtrees.
14-Jul-22 18:40:17 [modelacao.fi-F82B:1-8]<FTFICHA:30ad6> xtree warning: implicit replacement of ctl 0 with fewer rows (24 vs 18)
14-Jul-22 18:40:22 [modelacao.fi-F82B:1-8]<FTFICHA:30ad6> xtree warning: implicit replacement of ctl 0 with fewer rows (24 vs 22)

Thanks

Probably not. The situation is that you are using XTROP_CREATE but the specified control number (0) already exists. In that case, as an optimization, it changes the opcode to XTROP_REPLACE.

The main reason for the warning is that the new control has fewer rows that then original one, but the original rows are still there in memory. As long as they remain beyond the new ItemCount value, there shouldn't be any concern. But if you then use XTROP_APPEND, or maybe XTROP_DELSEL, I'm not completely sure that the extra rows wouldn't somehow get in the way.

The alternative would be to use XTROP_DELETE first, but that would likely cause some screen flickering. So maybe putting up with the warning message in the ashlog is the lesser of two annoyances.

Ok, thanks