search

sassoftware / saspy

A Python interface module to the SAS System. It works with Linux, Windows, and Mainframe SAS as well as with SAS in Viya.
https://sassoftware.github.io/saspy
Other
373 stars 150 forks source link

Java session does not always end when ._endsas() is called / when SASsession object goes out of scope #324

Closed DataSolutions23 closed 3 years ago

DataSolutions23 commented 4 years ago

Describe the bug I have noticed that there are scenarios when the java binary is not closed, when ._endsas() is called / the SASSession goes out of scope. Unfortunately I can not provide exact steps to reproduce this with, as it is quite intermittent. I was wondering 2 things:

  1. Is the PID for the java session accessible through SASPy?
  2. Is SASPy explicitly closing the java session? I traced through _endsas(), and was not able to see anything that was explicitly closing the java session.

Why this is important I have TONS of scripts that rely on SASPy, that execute on a nightly / daily basis. When I end up with orphaned processes, it starts to clog up my server

Expected behavior Calling _endsas() or having the SASsession object go out of scope will close the related java session

Screenshots If applicable, add screenshots to help explain your problem.

Desktop (please complete the following information):

Additional context If I could at very least access the PID for the java session, I may be able to track down exactly what is steps will reproduce the issue

tomweber-sas commented 4 years ago

Hey @DataSolutions23, I haven't seen this before, so lets dig in and see what's happening. First, to address some of your questions: 1) yes, you can access the PID of the Java sub-process that is created by saspy to interface to SAS. This is displayed when the connection is started, but you can directly reference it to, if necessary, from the underlying access method object. Below, see that the Java process is 31265, while the pid of the (remote in this case) SAS process is 20829

>>> import saspy
>>> sas = saspy.SASsession(cfgname='iomj')
SAS Connection established. Subprocess id is 31265

No encoding value provided. Will try to determine the correct encoding.
Setting encoding to utf_8 based upon the SAS session encoding value of utf-8.

>>> sas
Access Method         = IOM
SAS Config name       = iomj
SAS Config file       = /opt/tom/github/saspy/saspy/sascfg_personal.py
WORK Path             = /sastmp/SAS_work49410000515D_tom64-5/SAS_workE3A40000515D_tom64-5/
SAS Version           = 9.04.01M4D11092016
SASPy Version         = 3.5.3
Teach me SAS          = False
Batch                 = False
Results               = Pandas
SAS Session Encoding  = utf-8
Python Encoding value = utf_8
SAS process Pid value = 20829

>>> sas._io.pid
31265
>>>

Ahm but you're running on windows, so the pid is one more level of indirection, as the way the sub-proces is created is different on windows: java=1840 and SAS=20829:

>>> import saspy
>>> sas = saspy.SASsession(cfgname='winiomj')
SAS Connection established. Subprocess id is 1860

No encoding value provided. Will try to determine the correct encoding.
Setting encoding to utf_8 based upon the SAS session encoding value of utf-8.

>>> sas
Access Method         = IOM
SAS Config name       = winiomj
SAS Config file       = C:\ProgramData\Anaconda3\lib\site-packages\saspy\sascfg_personal.py
WORK Path             = /sastmp/SAS_work49410000515D_tom64-5/SAS_work4A7C0000515D_tom64-5/
SAS Version           = 9.04.01M4D11092016
SASPy Version         = 3.5.2
Teach me SAS          = False
Batch                 = False
Results               = Pandas
SAS Session Encoding  = utf-8
Python Encoding value = utf_8
SAS process Pid value = 20829

>>> sas._io.pid
<subprocess.Popen object at 0x00000158A7797C88>
>>> sas._io.pid.pid
1860
>>>

2) Yes, either when you issue sas.endsas() ('sas' being the SASsesion object in this case), or when Python garbage collection happens on the SASsession object (del), if that happens, I explicitly tell the Java process to cleanly shut down the SAS session that it's connected to and then cleanly terminate itself. I then wait for up to 5 seconds to see that the Java process terminated, and if it hasn't then I issue an OS Kill for the process to force terminataio. Then I return from endsas with no session established anymore. If, perhaps, the python process is abnormally terminating and neither endsas is explicitly called, nor is python cleaning up objects, then what happens would be up to the OS. Since the Java process is a sub-process of the Python process, if pthon goes away, it's sub-processes should be ended. But, it's windows, so who knows.

When I killed the python pid, on windows (manually as a test), with a SASsesison established, both the python process was terminated and the java sub-process was terminated, and the SAS process was terminated (a local SAS install), and the remote connection to a workspace server was ended (on the SAS side). So, I'm not seeing a case (with my testing just now) of that happening even with the python process abnormally terminating. So, this will be fun to track down :)

So, as this is intermittent, do you have any sense of if it's particular scripts, or if it's if the python program is terminating unexpectedly, of any kind of idea? Maybe having the pid now will let you correlate that info? As saspy is source code, if need, we can easily add some code at appropriate places to write out info (breadcrumbs) to see if endsas is being called or not, or any other place as necessary.

BTW, are you connecting to a local SAS install on your PC or a remote workspace server?

Thanks, Tom

DataSolutions23 commented 4 years ago

@tomweber-sas ,

I am connecting to a remote workspace server. I am going to update my scripts to start logging out the java pid, that way I can try to correlate what may be causing this to happen.

I have run a few tests myself, with allowing garbage collection to close out the session, and explicitly calling it, and I can not willingly reproduce it. I will hopefully have more information over the next few days,

That fact that you are running an OS kill on the pid, if the process doesn't self terminate, makes me believe that there may not be anything else that can be done, if the process is still running.

I will update my code today, and hopefully have some helpful information by next week.

Thanks for the quick reply on this!

tomweber-sas commented 4 years ago

Sure thing. If you can track it down to a particular script, maybe we can see if there something that can be coded different. I'm just not sure what circumstances would cause this, especially given what I'm observing; which I've tested in the past too; but it's good to double check. You have the latest version, can you show me your configuration definition for this, just for the sake of argument? Are you letting saspy set up the classpath and use the jars in it's install? If there were a jar mismatch, then maybe something could be happening to hang the process (maybe - guessing at possibilities here).

DataSolutions23 commented 3 years ago

@tomweber-sas,

Based off logging the PIDs of the Java processes, I was able this morning to at least find one scenario that causes the Java session to not close. There are likely other weird scenarios, but this is the one that came up this morning. I am not sure if there is anything that could be done about this specific scenario

Scenario 1:

  1. Script is kicked off via Windows Task Scheduler
  2. Script connects to SAS via SASPy
  3. Execution of SAS script hangs (This script runs daily, so it was a weird environmental thing, not the SAS code)
  4. Script is killed via force ending the scheduled task via windows task manager
  5. Java process stays active
tomweber-sas commented 3 years ago

Glad you could track it down now. So, I'm not familiar with that tool for scheduling things, but I'm guessing you're just running a python batch script that this tool kicks off? I wonder if it has a better way for cleaning up it's jobs that using TM to kill a process? What processes as associated with that tools' invocation? There may be something above the python process running saspy, and then it's sub-process java, which is then connected remotely to SAS over IOM. Is the python a sub-process of some process that tool starts up to run the job? When you kill a process, which process is it? TM doesn't appear to have a mode of killing the whole process tree, like some other tools, so I wonder if it's just a matter of using the right tool to cleanly bring down the whole set. This is all much more obvious, and works as you would expect, on Linux, so I'm not sure what is happening with all of this on your windows box. Out of curiosity, what it the environment issue that causes something about this to hang in the first place? Do you know what the actual problem causing that is; what's hanging where and why?

tomweber-sas commented 3 years ago

@DataSolutions23, is there anything else I can do to help out on this issue?

Thanks, Tom

DataSolutions23 commented 3 years ago

Sorry. Please go-ahead and close out this issue.

Thanks, JAy

From: Tom Weber notifications@github.com Sent: Thursday, November 12, 2020 10:51 AM To: sassoftware/saspy saspy@noreply.github.com Cc: Kissel, Jason Jason.Kissel@LibertyMutual.com; Mention mention@noreply.github.com Subject: {EXTERNAL} Re: [sassoftware/saspy] Java session does not always end when ._endsas() is called / when SASsession object goes out of scope (#324)

@DataSolutions23https://github.com/DataSolutions23, is there anything else I can do to help out on this issue?

Thanks, Tom

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHubhttps://github.com/sassoftware/saspy/issues/324#issuecomment-726163505, or unsubscribehttps://github.com/notifications/unsubscribe-auth/ARGLLKVVP6AFTWELEIOBSUDSPP76TANCNFSM4R664TPQ.

tomweber-sas commented 3 years ago

No problem, will do. Just trying to clean up old issues :). Let me know if you need anything else! Tom