Questions? Feedback?powered byOlark live chat software
Bug 3267

Invalid Reference in PBDWE170.DLL (17.2.0.1858) 07 November, 2019

Tyler Cruse
29 August, 2019
Product: PowerBuilder Category: DataWindow
Version: 2017 R3 Publishing: Public
Status: Reproducing Priority: P3
Classification: Resolution:
Tyler Cruse 07 November, 2019
Ken,
Thanks for the advice.  I have implemented steps 1 & 2.  It will take some time before we will know if it makes a difference.  
Thanks again.
Ken Guo 07 November, 2019
Hi Tyler,

I checked the code you submitted, I suggest you try the following:
1. Delete the following code in of_loop() or directly modify it to Yield()。 
        do while yield()
        loop

2. In the of_timer() function, add code of resetupdate() as it is shown below:
// There is a bug in DataStore, if you don’t execute update or destroy, it will lead to a memory leak very easily. 

time ltm_start, ltm_end
long ll_start, ll_end, ll_elapsed
string ls_process
datetime ldtm_now
ids_timers.resetupdate() //release update flag.
if ids_timers.rowcount() > 0 then


3. If the issue still exists after doing the above steps, I suggest you rewrite the code to make it create and destroy DataStore once in one loop.

Regards,
Ken
Tyler Cruse 06 November, 2019
d_timers.srd (6KB)

Datastore dataobject
Tyler Cruse 06 November, 2019
n_appmanager.sru (13KB)

Currently, the logical loop has the following:

if ll_elapsed < il_delay then WSleep( il_delay - ll_elapsed )
-- after last process item in of_timer()
where WSleep is defined as:
SUBROUTINE       WSleep( &
	ULONG dwMilliseconds &
	) Library "KERNEL32.DLL" &
      ALIAS FOR "Sleep"

The loop is written as follows:
do while isvalid( w_appservice )
	if ib_running then return
	ib_running = true
	of_timer()
	ib_running = false
	do while yield()
	loop
	GarbageCollect ( )
	 update ap_table_sync set modified_date = getdate() where table_name = 'APService.exe' using sqlca ;
	 commit using sqlca ;
loop
Ken Guo 05 November, 2019
Hi Tyler,

There are Loop statements in your application only, so your application is always running. Maybe it is related to this.
If it is allowed for the business logic, I suggest you try the following:
1. Add Sleep() function in the Loop statement and then try. For example, sleep(1).
2. Use a window instead of Loop via Timer to try and see if it works.

Regards,
Ken
Tyler Cruse 05 November, 2019
One more thing, I have looked at the SQL Server logs and there are no related entries.  Also the application logs that would have reported SQL errors from the application code is clean.
Tyler Cruse 05 November, 2019
Ken,
1)  Not really feasible due to the hospital environment
2) No increase in memory is reported by task manager
3) There are no timer events in this process loop, only yield loops
4) We have added lots of logging to this process loop.  The results are in every case the error is the same, just the datastore changes.  This happens on both 2017R3 and 2019 run times, 

The environment is a loop that does a select on a number of tables, checking to see if there is work pending and then process the work if it is pending.  Some of the work involves IO to file system, SQL statements/business logic and some to update table to indicate processing is active.  The entire loop is part of the NVO, so releasing and restarting the process would be the equivalent of stopping the service and restarting the service.

The one datastore that has had multiple failures has been replaced with in-line SQL to eliminate that particular object from the mix. Unfortunately, this is old code that has lots of datastores used for most of the SQL access so a major task to update the code to better/faster methods is not something the company is willing to authorize. If major effort was authorized I would probably re-write as .Net Core 3.0 service. Currently, the customer has no visibility into the issue since we have hidden the issue with external code to restart the service after failure within about 10 seconds.

My request to Appeon is for the exception to be caught and error (with some information) be returned to the application.
Ken Guo 05 November, 2019
Hi Tyler,

Due to that we can’t reproduce it on our side and the failure happens after your application runs for a while, I suggest you:
1. Try to launch the application through double-clicking the EXE instead of using Windows Service and see if the issue still exists. If yes, use Run as Administrator to run the EXE and see if it works.
2. Check the loop statements in the application and see whether there are code will lead to the increase of memory. If it is allowed for the business logic, I suggest you release NVO and DataStore in the loop.
3. If there is Timer event, please check the code as well and refer to #2 to modify it.
4. Check the code which is been executed ceaselessly and comment them one by one so that you can find out exactly which line of code is causing the issue.

Regards,
Ken
Chris Pollach 01 November, 2019
Hi Tyler;

  Thanks for trying those suggestions and the extra feedback on your App's situation!

  I will now included the main Support/Engineering team in on this ticket to see if they can also suggest any further remedies or options to try.

Regards ... Chris
Tyler Cruse 01 November, 2019
Update, changed to 2019 PB version, the failure rate is still about weekly.  No change in error recorded in Windows Event Viewer, added all of your suggestions to the code, as below:
//lds_find = create u__ds
//
//lds_find.dataobject = 'd_findparentforgrouping'
//lds_find.settransobject(SQLCA)
//
//if lds_find.retrieve(al_id, al_locid, al_transType, al_priority, as_process, al_status, al_pick_by, as_value, ls_ped) < 1 then
//	ll_rtn = 0
//else
//	ll_rtn = lds_find.object.parent_pick_id[1]
//	if isnull(ll_rtn) then ll_rtn = 0
//end if
//
//lds_find.reset() 
//lds_find.DataObject = ""
//destroy lds_find

Have seen other datastores fail, but this one seems to be most often.  Replaced with in line call to see if that will make occurrence less often.  As:
DECLARE findparentforgrouping PROCEDURE FOR dbo.d_findparentforgrouping 
	@al_id = :al_id, @al_locid = :al_locid, @al_transtype = :al_transType, 
	@al_priority = :al_priority, @as_process = :as_process, @al_status =:al_status, 
	@al_pick_by = :al_pick_by, @as_value = :as_value, @ls_ped = :ls_ped
	using SQLCA;
EXECUTE findparentforgrouping;
if SQLCA.sqlcode = 0 THEN 
	FETCH findparentforgrouping into :ll_rtn ;
end if
CLOSE  findparentforgrouping ;

if IsNull( ll_rtn ) THEN return 0
if ll_rtn < 1 THEN return 0

Note: SQL moved to stored procedure but no other real changes
Chris Pollach 09 October, 2019
Hi Tyler;

  Since you seem to be using DataStores, can you try this little trick that I always use with my PB Apps ...

1) Create a PB.INI file of your own.
2) Create a [DataStore Behavior] section.
3) Add to this section ...
  UseHwnd=no
4) Copy this PB.INI file into the same folder as your App's EXE on deployment

Note1:  ; No = do NOT use MS-Window handles in DS processing (Default is yes). 
        ; "No" gives much better performance and less memory usage!

Note2:  Add this section to your working PB IDE's PB.INI for the same effect.

Regards ... Chris
Tyler Cruse 09 October, 2019
Upadate, check for setTransObject does not seem to fail, added reset and clear of dataobject in all cases that have the same pattern of code.
Also, tried letting garbage collect handle the destroy.
The problem still occurs, now in one day instead of 7 or 8 days.  The failure does not follow the particular data store data object.  Failures on other data store objects trapped.  
Suspect a memory leak that eventually kills the app.  Added forced garbage collect and yield in the process loop.
Will let you know the results of this test.
Chris Pollach 07 October, 2019
Hi Tyler;

  The TRY..CATCH command would only be invoked if the i_stage pointer variable was either NULL or invalid.

regards ... Chris
Tyler Cruse 07 October, 2019
Thanks, added code to check return code for settransobject(sqlca) and reset/set dataobject;  for next round of test code, 
I expected the try-catch to have been invoked.

	choose case ls_process
		case 'staging'
			try
				i_stage.event ue_timer()
			catch( RUNTIMEERROR re1 )
				guo_lib.logerror( 'Staging RUN TIME ERROR', string(re1.number), true )
				guo_lib.logerror( 'Error Text', re1.Text, true )
				guo_lib.logerror( 'Error Class', re1.Class, false )
				guo_lib.logerror( 'Error Object', re1.objectname, false )
				guo_lib.logerror( 'Error Script', re1.routinename, false )
				guo_lib.logerror( 'Error Line', String(re1.line), false )
			catch( EXCEPTION ex1 )
				guo_lib.logerror( 'Staging EXCEPTION', ex1.text, true )
			end try
		case 'queuing'
			try
				i_queue.event ue_timer()
.....

Note: ue_timer no longer has any timer related logic, that was removed long before I got involved with this company
Chris Pollach 07 October, 2019
Hi Tyler;

  In reviewing your code, I see that it does not check to see if the SetTransObject() command worked.

  As for the Destroy of the DS, here is what I always do ...

1) DS.Reset ()
2) DS.DataObject = ""
3) Yield()  // optional
3) Destroy DS

Regards ... Chris
Tyler Cruse 07 October, 2019
Apparently the faulting code segment:
LONG ll_rtn
string ls_ped
u__ds lds_find

ls_ped = ''
if ab_ped then ls_ped = 'Pediatric'

if al_pick_by = 2 then
	if al_transtype = g_sql.of_getpicktype('Cart Fill') then
	else
		al_pick_by = 3
	end if
end if

as_value = lower(trim(as_value))

lds_find = create u__ds

lds_find.dataobject = 'd_findparentforgrouping'
lds_find.settransobject(SQLCA)

if lds_find.retrieve(al_id, al_locid, al_transType, al_priority, as_process, al_status, al_pick_by, as_value, ls_ped) < 1 then
	ll_rtn = 0
else
	ll_rtn = lds_find.object.parent_pick_id[1]
	if isnull(ll_rtn) then ll_rtn = 0
end if

// removed destroy, safer to let garbage collection handle freeing the memory  (10/05/2019)
// waiting for results as to if this helps/stops the problem
destroy lds_find

RETURN ll_rtn

---------------------------------------
forward
global type u__ds from datastore
end type
end forward

global type u__ds from datastore
end type
global u__ds u__ds

event sqlpreview;string ls_request, ls_type, ls_buffer

choose case request
	case PreviewFunctionRetrieve!
		ls_request = "Retrieve"
	case PreviewFunctionReselectRow!
		ls_request = "ReselectRow"
	case PreviewFunctionUpdate!
		ls_request = "Update"
	case else
		ls_request = "UNKNOWN"
end choose

choose case sqltype
	case PreviewSelect!
		ls_type = "Select"
	case PreviewInsert!
		ls_type = "Insert"
	case PreviewDelete!
		ls_type = "Delete"
	case PreviewUpdate!
		ls_type = "Update"
	case else
		ls_type = "UNKNOWN"
end choose

choose case buffer
	case Primary!
		ls_buffer = "Primary" 
	case Delete!
		ls_buffer = "Delete" 
	case Filter!
		ls_buffer = "Filter" 
	case else
		ls_buffer = "UNKNOWN"
end choose

guo_lib.logdebug('DATASTORE SQL PREVIEW', dataobject, false, GB_DEBUGLOGSQL)
guo_lib.logdebug('~tFunction', ls_request, false, GB_DEBUGLOGSQL)
guo_lib.logdebug('~tStatement Type', ls_type, false, GB_DEBUGLOGSQL)
guo_lib.logdebug("~tBuffer", ls_buffer, false, GB_DEBUGLOGSQL)
guo_lib.logdebug("~tRow", string(row), false, GB_DEBUGLOGSQL)
guo_lib.logdebug('~tSQLSyntax', sqlsyntax, false, GB_DEBUGLOGSQL)

end event

event error;guo_lib.logerror('DATASTORE ERROR EVENT', string(errornumber), true)
guo_lib.logerror('~tError Text', errorText, true)
guo_lib.logerror('~tError Class', errorWindowMenu, false)
guo_lib.logerror('~tError Object', errorObject, false)
guo_lib.logerror('~tError Script', errorScript, false)
guo_lib.logerror('~tError Line', string(errorLine), false)

end event

event dberror;string ls_buffer

choose case buffer
	case Primary!
		ls_buffer = "Primary" 
	case Delete!
		ls_buffer = "Delete" 
	case Filter!
		ls_buffer = "Filter" 
end choose

guo_lib.logerror('DATASTORE DBERROR EVENT', dataobject, true)
guo_lib.logerror('~tSQLErrText', sqlerrtext, true)
guo_lib.logerror('~tSQLDBCode', string(sqldbcode), false)
guo_lib.logerror("~tBuffer", ls_buffer, false)
guo_lib.logerror("~tRow", string(row), false)
guo_lib.logerror('~tSQLSyntax', sqlsyntax, false)

return 0

end event

on u__ds.create
call super::create
TriggerEvent( this, "constructor" )
end on

on u__ds.destroy
TriggerEvent( this, "destructor" )
call super::destroy
end on

-------------------------------
release 12.5;
datawindow(units=0 timer_interval=0 color=1073741824 brushmode=0 transparency=0 gradient.angle=0 gradient.color=8421504 gradient.focus=0 gradient.repetition.count=0 gradient.repetition.length=100 gradient.repetition.mode=0 gradient.scale=100 gradient.spread=100 gradient.transparency=0 picture.blur=0 picture.clip.bottom=0 picture.clip.left=0 picture.clip.right=0 picture.clip.top=0 picture.mode=0 picture.scale.x=100 picture.scale.y=100 picture.transparency=0 processing=0 HTMLDW=no print.printername="" print.documentname="" print.orientation = 0 print.margin.left = 110 print.margin.right = 110 print.margin.top = 96 print.margin.bottom = 96 print.paper.source = 0 print.paper.size = 0 print.canusedefaultprinter=yes print.prompt=no print.buttons=no print.preview.buttons=no print.cliptext=no print.overrideprintjob=no print.collate=yes print.background=no print.preview.background=no print.preview.outline=yes hidegrayline=no showbackcoloronxp=no picture.file="" )
header(height=0 color="536870912" transparency="0" gradient.color="8421504" gradient.transparency="0" gradient.angle="0" brushmode="0" gradient.repetition.mode="0" gradient.repetition.count="0" gradient.repetition.length="100" gradient.focus="0" gradient.scale="100" gradient.spread="100" )
summary(height=0 color="536870912" transparency="0" gradient.color="8421504" gradient.transparency="0" gradient.angle="0" brushmode="0" gradient.repetition.mode="0" gradient.repetition.count="0" gradient.repetition.length="100" gradient.focus="0" gradient.scale="100" gradient.spread="100" )
footer(height=0 color="536870912" transparency="0" gradient.color="8421504" gradient.transparency="0" gradient.angle="0" brushmode="0" gradient.repetition.mode="0" gradient.repetition.count="0" gradient.repetition.length="100" gradient.focus="0" gradient.scale="100" gradient.spread="100" )
detail(height=84 color="536870912" transparency="0" gradient.color="8421504" gradient.transparency="0" gradient.angle="0" brushmode="0" gradient.repetition.mode="0" gradient.repetition.count="0" gradient.repetition.length="100" gradient.focus="0" gradient.scale="100" gradient.spread="100" )
table(column=(type=long updatewhereclause=yes name=parent_pick_id dbname="parent_pick_id" )
 retrieve="WITH DetailValue ( pick_queue_id, detail_desc, detail_value ) AS (
     SELECT AP_PICK_DETAILS.pick_queue_li
          , LOWER(LTRIM(RTRIM(AP_PICK_DETAIL_TYPE.pdd_xml_code)))
          , AP_PICK_DETAILS.detail_value
       FROM AP_PICK_DETAILS WITH (NOLOCK)
          INNER JOIN AP_PICK_DETAIL_TYPE WITH (NOLOCK)
             ON LOWER(LTRIM(RTRIM(AP_PICK_DETAIL_TYPE.pdd_xml_code))) IN ( 'patientname', 'msg9', 'labelbanner' )
            AND AP_PICK_DETAIL_TYPE.pick_detail_type_id = AP_PICK_DETAILS.detail_type_li
)
SELECT MAX(AP_PICK_QUEUE.parent_pick_li) AS parent_pick_id
  FROM AP_PICK_QUEUE WITH (NOLOCK)
     LEFT OUTER JOIN DetailValue AS PatientName
        ON PatientName.pick_queue_id = AP_PICK_QUEUE.pick_queue_id
       AND PatientName.detail_desc = 'patientname'
     LEFT OUTER JOIN DetailValue AS Msg9
        ON Msg9.pick_queue_id = AP_PICK_QUEUE.pick_queue_id
       AND Msg9.detail_desc = 'msg9'
     LEFT OUTER JOIN DetailValue AS Pediatric
        ON Pediatric.pick_queue_id = AP_PICK_QUEUE.pick_queue_id
       AND Pediatric.detail_desc = 'labelbanner'
       AND LOWER(LTRIM(RTRIM(Pediatric.detail_value))) = 'pediatric'
 WHERE AP_PICK_QUEUE.parent_pick_li <> :al_id
   AND AP_PICK_QUEUE.loc_detail_li = :al_locid
   AND AP_PICK_QUEUE.pick_type_li = :al_transType
   AND AP_PICK_QUEUE.priority = :al_priority
   AND AP_PICK_QUEUE.pick_process = :as_process
   AND AP_PICK_QUEUE.pick_status_li = :al_status
   AND ( ( LOWER(LTRIM(RTRIM(ISNULL(:ls_ped, '')))) != 'pediatric' AND ISNULL(Pediatric.pick_queue_id, 0) = 0 )
    OR   ( LOWER(LTRIM(RTRIM(ISNULL(:ls_ped, ''))))  = 'pediatric' AND ISNULL(Pediatric.pick_queue_id, 0) > 0 ) )
   AND CASE :al_pick_by
         WHEN 2 THEN PatientName.detail_value
         WHEN 3 THEN Msg9.detail_value
         ELSE ''
       END =
       CASE :al_pick_by
         WHEN 1 THEN ''
         ELSE :as_value
       END
;
" arguments=(("al_id", number),("al_locid", number),("al_transType", number),("al_priority", number),("as_process", string),("al_status", number),("al_pick_by", number),("as_value", string),("ls_ped", string))  sort="parent_pick_id D " )
column(band=detail id=1 alignment="0" tabsequence=32766 border="0" color="33554432" x="0" y="0" height="88" width="471" format="[general]" html.valueishtml="0"  name=parent_pick_id visible="1" edit.limit=0 edit.case=any edit.focusrectangle=no edit.autoselect=no  font.face="Tahoma" font.height="-10" font.weight="400"  font.family="2" font.pitch="2" font.charset="0" background.mode="2" background.color="1073741824" background.transparency="0" background.gradient.color="8421504" background.gradient.transparency="0" background.gradient.angle="0" background.brushmode="0" background.gradient.repetition.mode="0" background.gradient.repetition.count="0" background.gradient.repetition.length="100" background.gradient.focus="0" background.gradient.scale="100" background.gradient.spread="100" tooltip.backcolor="134217752" tooltip.delay.initial="0" tooltip.delay.visible="32000" tooltip.enabled="0" tooltip.hasclosebutton="0" tooltip.icon="0" tooltip.isbubble="0" tooltip.maxwidth="0" tooltip.textcolor="134217751" tooltip.transparency="0" transparency="0" accessiblename="parent_pick_id" )
htmltable(border="1" )
htmlgen(clientevents="1" clientvalidation="1" clientcomputedfields="1" clientformatting="0" clientscriptable="0" generatejavascript="1" encodeselflinkargs="1" netscapelayers="0" pagingmethod=0 generatedddwframes="1" )
xhtmlgen() cssgen(sessionspecific="0" )
xmlgen(inline="0" )
xsltgen()
jsgen()
export.xml(headgroups="1" includewhitespace="0" metadatatype=0 savemetadata=0 )
import.xml()
export.pdf(method=0 distill.custompostscript="0" xslfop.print="0" )
export.xhtml()
-----------------------------
Chris Pollach 10 September, 2019
Hi Tyler;

  Thank you for confirmation!

  I cannot say what your issue is without a simple test case that replicates this crash. However as you already stated, this only happens maybe once a week. So it would be (I would imagine) extremely had for you and Appeon to replicate.

  I see that you are using the "srvany" product for running your PB App as an O/S Service. I wonder if this could be your issue?

Regards ... Chris
Tyler Cruse 10 September, 2019
No timer events involved.  The processes are entered into DW with next time to process column and the DW is polled row by row in a loop
Chris Pollach 30 August, 2019
Hi Tyler;
  
   Does your PB App use Timers (ie: Timing object to Window timer) and/or the IDLE timer? If so, what is happening when these events fire?

Regards ... Chris
Chris Pollach 30 August, 2019
Email from customer (Tyler) ...

-------------------------------------------------------------

Thanks I will check the items that you reference.
However, at this point none of these conditions come to mind.
Since each of these operations happen often, usually with only 100-200 ms wait between the polls, the expression/computed column condition seems unlikely.
Also, the “crash” seems  happen during idle activity times, e.g. nothing to dispense, nothing to print,  nothing to import, nothing to export, no backup required ….  It appears that the DW controls would be returning 0 rows during this time.
  
There are DBERROR and ERROR events in every case, and have in other cases been shown to work correctly.

Nice to see that you are still active in the PB world, been a lot of years since the 12.5.x time frame.
Chris Pollach 29 August, 2019
Hi Tyler;

  The "pbdwe170" module is the Data Window Expression evaluator. Typically when we see this type of random error, the cause is either:

a) Missing DW object
   Could be caused by a Destroy or DC/DS.Dataobject = "" command
b) Dynamic change to the DWO's properties. Especially an "expression", in a Modify() command.
c) Bad data causing a computed column or expression error.

In the above cases, the DW Control or DataStore "container" should catch the above errors if the App has the ERRROR and DBERROR events coded around the DC/DS controls.

Regards ... Chris
Tyler Cruse 29 August, 2019
*Phenomenon:
Application has no UI running as windows service (srvany).  Failure happens about once a week.
Application is basically in a "poll loop" checking for work to perform based on DB contents.  Failure does not occur at any regular time or usage level,

*Reproduce Steps:
Can supply code and sample database on request.  

Remarks:
Fault bucket , type 0
Event Name: APPCRASH
Response: Not available
Cab Id: 0

Problem signature:
P1: appservice.exe
P2: 3.5.0.10
P3: 5c4c50b1
P4: pbdwe170.dll
P5: 17.2.0.1858
P6: 5b55f84d
P7: c0000005
P8: 00000000002a9fe7
P9: 
P10: 

Attached files:

These files may be available here:
C:\ProgramData\Microsoft\Windows\WER\ReportQueue\AppCrash_appservice.exe_2dcacdd77494fefe1afb83268041aa49d1251a2c_729ba3ec_0619fdab

Analysis symbol: 
Rechecking for solution: 0
Report Id: 8f5ce43b-c4f8-4c0f-a772-6c5a63892781
Report Status: 4


Faulting application name: appservice.exe, version: 3.5.0.10, time stamp: 0x5c4c50b1
Faulting module name: pbdwe170.dll, version: 17.2.0.1858, time stamp: 0x5b55f84d
Exception code: 0xc0000005
Fault offset: 0x00000000002a9fe7
Faulting process id: 0xb94
Faulting application start time: 0x01d5585be0cb293f
Faulting application path: C:\Program Files (x86)\Talyst\AutoPharmServer\appservice.exe
Faulting module path: C:\Program Files (x86)\Appeon\Shared\PowerBuilder\x64\pbdwe170.dll
Report Id: 8f5ce43b-c4f8-4c0f-a772-6c5a63892781
Faulting package full name: 
Faulting package-relative application ID: 



Application: appservice.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an unhandled exception.
Exception Info: exception code c0000005, exception address 000000006D2F9FE7
Stack:


Fault bucket 2176118087599235456, type 4
Event Name: APPCRASH
Response: Not available
Cab Id: 0

Problem signature:
P1: appservice.exe
P2: 3.5.0.10
P3: 5c4c50b1
P4: pbdwe170.dll
P5: 17.2.0.1858
P6: 5b55f84d
P7: c0000005
P8: 00000000002a9fe7
P9: 
P10:
OS:
Windows Server 2016 
Platform:
64-bit 
Database Type:
Microsoft SQL Server 
Database Version:
2016