Making FoxPro Ducky – Part 8 (Drowning In A Lake Of Files)

To recap from Part 1, the goals of this rabbit hole project were to use DuckDB’s fast processing engine alongside an existing Visual FoxPro 9 (VFP) application, to take advantage of DuckDB’s import/query speed on large datasets (100M+ rows, ~2GB) while keeping VFP as the primary application layer. The primary technical obstacle was that DuckDB only ships a 64-bit ODBC driver, and VFP9 only supports 32-bit ODBC which ruled out a direct database connection.

In case you’ve skipped ahead, perhaps I should offer a status update. So far, Claude and I have been working together pretty amicably and we’ve accomplished a lot. Most of it has been proving what doesn’t work or if it works, it isn’t practical. But, there have been some glimmers of hope as well. We’ve proven DuckDB is a monster when it come to gobbling up files and importing them into databases whether they are in-memory or persistent. It is actually incredible what this tiny relational database engine can really do. We have proven I can shell out of VFP, spawn an instance of DuckDB with a named pipe object inside of VFP and I can push commands directly into the DuckDB CLI behind the scenes without exposing the process to the user. We have proven DuckDB can import data directly to it’s own internal database format or a SQLite database or even to a classic DBF format which can be read natively inside of VFP.

You might think by reading the previous paragraph, I had already achieved the original goal for this project. I can make a round trip now from a raw CSV, JSON or other formatted file, import it into DuckDB, issue a query against the DuckDB database and then make the results available to VFP. But, I still wanted to test this on a grander scale and the place to start was by scaling up the database, looping through some queries and getting some test results.

Many years ago, I wrote a software product which helped telemarketers comply with the Telemarketing Sales Rule. The rule required marketers to scrub all of the numbers they wished to call against the Do-Not-Call (DNC) list collected by the Federal Trade Commission. The idea was if you didn’t want to get telephone calls from marketing people, you could add your telephone number to the list and American telemarketers would be required to take your phone number off their call lists and avoid calling you unless they had a prior business relationship with you. That’s really a separate story with its own twists and turns, and I’ll save that for another day.

Suffice it to say, I had a very large file of DNC telephone numbers left over from that previous project which I thought would give me a way to really put DuckDB through its paces. The file consisted of two fields (area code and phone number) per record and it contained 191.5 million records. I also wanted to start putting some progress update information into my test program, so I could start working out how the user interface might work in a large scale configuration. The new code would include the procedure HiddenShellProcess Claude wrote to give me access to a named-pipe into DuckDB plus I also wanted try to make the presentation to the user a little nicer. NOTE: the code below will reference a progressnotes object in a  _therm class which I use to provide progress notes to my users during a loop, but I won’t be documenting that code here. You can substitute your own progress display methods if you like. Also, this test does not include using temporary cursors or DBFs as I was trying to isolate the exact overhead of doing the work and not include the overhead of storing or processing the results. The only VFP-side updates will be to the array that is created.  

* Import LARGE Text File and Save as DuckDb Database
* Issue Multiple Queries to Hidden process and import query results into VFP
****************************************************************************
LOCAL loShell, lcCmdString, lnResult
SET SAFETY OFF
CLEAR

loProgress = NEWOBJECT("_progressnotes", "_therm")
loProgress.SHOW()
loProgress.UPDATE('Importing Data: ')

SET PROCEDURE TO HiddenShellProcess ADDITIVE && Load Claude's Procedure
loProc = CREATEOBJECT("HiddenShellProcess") && Create an object to call methods

DIMENSION laPhoneList[15,2]

laPhoneList[1,1] = "201-555-7731"
laPhoneList[2,1] = "301-555-6897"
laPhoneList[3,1] = "401-555-3524"
laPhoneList[4,1] = "501-555-6740"
laPhoneList[5,1] = "601-555-9246"
laPhoneList[6,1] = "701-555-4231"
laPhoneList[7,1] = "801-555-2373"
laPhoneList[8,1] = "901-555-2272"
laPhoneList[9,1] = "101-555-9552"
laPhoneList[10,1] = "111-555-5345"
laPhoneList[11,1] = "121-555-6477"
laPhoneList[12,1] = "131-555-9370"
laPhoneList[13,1] = "141-555-5110"
laPhoneList[14,1] = "151-555-2928"
laPhoneList[15,1] = "161-555-6650"

lcExeDir = "C:\temp\scrubber\"   && or wherever your files actually live
lcCmdLine = '"' + FULLPATH("duckdb.exe", lcExeDir) + '" "' + FULLPATH(".\clsdata.db", lcExeDir) + '"'
lcLogFile = FULLPATH(".\duckdb_console.log", lcExeDir)
lcCmdDone = FULLPATH(".\cmd.done", lcExeDir)
lcResults = FULLPATH(".\Results.out", lcExeDir)
lcImportFile = "T:/TPC/Active/Scrubber/import/bigfile1.txt"
DBExists = FILE("C:\temp\scrubber\clsdata.db",1)
lnBegProcess = SECONDS()

m.loProgress.UPDATE("Opening File: " + ALLTRIM("clsdata.db"))

IF loProc.Start(lcCmdLine, lcExeDir, lcLogFile)

	IF !DBExists
	
		DoneClear(lcCmdDone)
			
		TEXT TO lcSQLCmd TEXTMERGE NOSHOW
		CREATE TABLE dncdata AS (
			SELECT * 
			FROM read_csv('<>', 
			delim = ',', 
			header = false,
			columns = { 'AreaCode': 'VARCHAR',
						'PhoneNbr': 'VARCHAR'}));
		COPY (SELECT 1) TO "<<STRTRAN(lcCmdDone,'\','/')>>";
		ENDTEXT

		STRTOFILE(lcSQLCmd,".\scrubber\dbcreate.sql")
		loProgress.UPDATE('Importing Data From: ' + JUSTFNAME(lcImportFile))
		loProc.SendCommand(lcSQLCmd)

	ELSE
	
		TEXT TO lcSQLCmd TEXTMERGE NOSHOW
		COPY (SELECT 1) TO "<<STRTRAN(lcCmdDone,'\','/')>>";
		ENDTEXT

		STRTOFILE(lcSQLCmd,".\scrubber\dbopen.sql")
		loProc.SendCommand(lcSQLCmd)

	ENDIF

	IF WaitForDuckDb(loProgress,lcCmdDone)

		* Wait for DuckDB to write the cmd.done file and afterwards do nothing but leave the instance of DuckDB open for further processing. 

	ENDIF
	
	loProgress.UPDATE('Done.')
	
ELSE    

	? "CreateProcess failed, Win32 error: " + TRANSFORM(loProc.nLastError)

ENDIF

lnEndProcess = SECONDS()

lnBegProcess = SECONDS()
loProgress.UPDATE('Time To Open DB: ' + TRANSFORM(lnEndProcess-lnBegProcess) + " seconds.")
loProgress.waitabit(1.5)

m.loProgress.UPDATE("")
m.loProgress.UPDATE("Processing Requests: ")

FOR lnLoopCnt = 1 TO ALEN(laPhoneList,1)

	DoneClear(lcCmdDone)

	loProgress.UPDATE('Look Up... ' + laPhoneList[lnLoopCnt,1])
		
	TEXT TO lcSQLCmd TEXTMERGE NOSHOW
	COPY (	SELECT 1 as CNT 
			FROM dncdata 
			WHERE AreaCode = '<<LEFT(laPhoneList[lnLoopCnt,1],3)>>' and PhoneNbr = '<<STRTRAN(substr(laPhoneList[lnLoopCnt,1],5,8),"-")>>')
	TO "<<STRTRAN(lcResults,'\','/')>>" (HEADER false);
	COPY (SELECT 1) TO "<<STRTRAN(lcCmdDone,'\','/')>>";
	ENDTEXT

	STRTOFILE(lcSQLCmd,".\scrubber\dblookup.sql")
	loProc.SendCommand(lcSQLCmd)

	DO WHILE .t.

		IF FILE("&lcCmdDone")

			laPhoneList[lnLoopCnt,2] = VAL(ALLTRIM(FILETOSTR("&lcResults")))
			EXIT
							
		ENDIF
		
	ENDDO

ENDFOR

lnEndProcess = SECONDS()
loProgress.UPDATE('Time To Open DB: ' + TRANSFORM(lnEndProcess-lnBegProcess) + " seconds.")
loProgress.waitabit(1.5)

IF WaitForDuckDb(loProgress,lcCmdDone)

	loProc.Stop()

ENDIF


RETURN

FUNCTION DoneClear
LPARAMETERS tcCmdDoneFile

IF FILE("&tcCmdDoneFile")
	DELETE FILE "&tcCmdDoneFile"
ENDIF

RETURN

ENDFUNC

FUNCTION WaitForDuckDb
LPARAMETERS toProgress, tcCmdDoneFile
leRetVal = .f.

	DO WHILE .t.

		toProgress.UPDATE('Please wait... ' + TRANSFORM(SECONDS() - lnBegProcess) + " seconds.", .t.)
	
		IF FILE("&tcCmdDoneFile")
			leRetVal = .T.
			EXIT
		ENDIF
		
	ENDDO

  RETURN leRetVal

ENDFUNC

The outline of the logic is as follows:

1. Setup the environment, create the loProgress Object and create the loProc object which gets us access to the methods of the HiddenShellProcess.
2. Dimension an array where the first element is a phone number to test and the second element will store the results of our queries.
3. Populate the test array.
4. Init all of the paths required for the program
5. Call the loProc.Start method to spawn the DuckDB CLI instance and establish the named pipe to DuckDB.
6. Check to see if DBExists is FALSE, throw an error. IF DBExists is TRUE, then build the string lcSQLCmd to create the dncdata table and import the data directly from the lcImportFile. lcSQLCmd also has a secondary command to create a file named “cmd.done” when the import is finished. NOTE: A production system would probably include some code to test the table exists already, but I didn’t do it for this test.  The same logic would apply to Step 7 as well.
7. If DBExists is TRUE, then assume the data has already been imported and continue processing.
8. Create a FOR…NEXT loop to scan through the array and send a query command string to DuckDB for each row in the array and test if the phone number is found in the dncdata table
9. Write a one or a zero to a file named “results.out”
10. VFP will wait for the creation of the “cmd.done” file each time before reading the “results.out” with the FILETOSTR command and storing the read result value in the second element of the array row.

And, it once again, the logic worked as I planned.

DuckDB took a just 16.19 seconds to import 191 million records into a database file 845Mb in size which really surprised me because the original text file was 2.2Gb. Not sure what voodoo DuckDB is using, but size of the final persistent DuckDb database was impressive in it’s own right.

The batch query process worked well too, even though it was a bit simplistic, the program accomplished the lookups for 15 telephone numbers in 1.719 seconds. Dividing 1.719 seconds by 15 works out to just 0.1146 seconds per look up.

Once again, I found the process worked great, but unfortunately when you do a little math, what seems impressive on the surface, fails to scale.

Let’s assume I had a file of 5,000 telephone numbers I wanted to scrub against the DNC list (this a very average request for my scrubber clients), the 0.1146 seconds per lookup turns into a grand total of 573 seconds or 9.55 minutes to finish the scrub process. For comparison purposes, my original scrubber program written in native VFP accomplishes the same task and more in about 10 seconds.

In an effort to shave a little off the individual look up times, I asked Claude if there a way to write the results to a memory location (as an example, something like dumping results to the clipboard) which might be accessible by both DuckDB and VFP9? Claude reminded me that the clipboard probably was a bad idea since it would probably conflict with whatever else the user was doing. But Claude also pointed out since I was writing a 1-byte file 15 times — Windows’ file system cache (lazy-write) means those writes are essentially already RAM-speed; NTFS doesn’t force a physical disk write for something that small unless you explicitly call FlushFileBuffers. So, it’s quite possible the disk I/O itself is a negligible fraction of the 1.719 seconds, and the real cost lay somewhere else — perhaps it was DuckDB’s query planning/execution time per lookup.

Claude also suggested if I wanted to eliminate the result file completely, perhaps I could consider using a second named pipe carrying results back, instead of a file. Given we already have a working stdin-pipe infrastructure, Claude thought I could consider adding a stdout-pipe to our procedure especially if testing shows the file I/O was genuinely the bottleneck, but Claude also stated there was a decent chance the time was affected by something a pipe rewrite wouldn’t fix.

Additionally, Claude noted the raw stdout from the DuckDB CLI would not be a clean, single-value data format — it would include whatever the CLI normally printed to a terminal: column headers, box-drawing borders, row counts, timing info if .timer on is set, etc., depending on your .mode setting. It would be important to set .mode csv (or .mode json) right after launching, so what comes back through the pipe is parseable rather than human-formatted table output. I would also need my own framing convention — since stdout-pipe just gives a raw byte stream with no built-in “this is where one result ends and another begins,” so I would need each query to end with something unambiguous (a newline-terminated sentinel line, for instance) so the read loop knows when it’s gotten a complete response versus a partial one arriving mid-read.

After giving it some serious thought, I decided perhaps the stdout-pipe method would create more problems than it would solve and it was clear that even Claude wasn’t convinced the file method of communicating with VFP was where most of the time delay was going to be found. Claude’s recommendation was to expand the testing to try and isolate exactly where the problem was because a sample size of 15 records simply didn’t get us far enough to exclude the cost of overtime.

So, I created multiple test files (Small – 15 records, Medium – 500 records, and Large – 4300 records) and I ran tests on all three file sizes. The Small file had the slowest average time per record, but both the medium and large tests came in at .021 seconds per lookup. The large file took a total of about 3.5 minutes to complete. Which didn’t seem horrible until I went back and compared those numbers to the same process I built in VFP many years ago which completed the same lookup of 4300 records in just under 12 seconds.

My thought was the difference in the VFP results and the DuckDb results might be because the VFP tables all were indexed and took advantage of VFP’s Rushmore technology. I had also decided in this round of testing to consolidate the cmd.done file and the results.out file to only write one file instead of two. In other words, I would write the results of the query in the cmd.done file instead of a separate file.

As elegant as the solution of combining the two files sounded, I found it created a new problem. I discovered a timing issue where DuckDB retains a lock on the cmd.done file just long enough to prevent VFP from reading the cmd.done file with FILETOSTR and it causes the process to crash. I could probably wrap the FILETOSTR command in a TRY…CATCH…FINALLY command to wait for the lock to be released before reading the file, but the wait time would cost me any savings I’d gotten from using one file instead of two to communicate results to VFP.

Claude confirm DuckDB supported indexes, but also noted some disbelief in the idea that an index would solve the problem. Claude felt it was more a cost of the round trip to do just one lookup at a time. In fact, Claude thought the solution was to batch all of my queries into “chunks” to do multiple lookups in each round trip to DuckDB and back. The bigger the file, the bigger the chunk. The idea was with 4,300 records broken into chunks of 300 records per chunk, that would only be 14 round-trips instead of 4,300 — roughly a 300x reduction in dispatch overhead — while still giving the user a progress update every fraction of a second to a couple seconds, depending on chunk size.

Claude also suggested changing my query to utilize the EXISTS command instead of a direct comparison. The logic of which looks like this:

SELECT
    k.lookup_key,
    EXISTS (
        SELECT 1 FROM big_table t WHERE t.some_key = k.lookup_key
    ) AS found
FROM lookup_keys k;

The EXISTS change cut the time per record look up from 0.021 seconds per record on the large test file to 0.014 which is better but still doesn’t achieve what I felt was really achievable. Claude was suggesting writing each query result to a unique file name in order to avoid the locking of the files (which seemed to be getting worse the bigger the files got) and Just like that, I saw myself drowning in a sea of files.

I also saw potential problems associated with the logistics of either dealing with these files on the fly or after the processing was done. Dealing with it on the fly would mean that if I tried to delete a file that was still locked, I’d have to wait for the lock to be released or skip it and deal with it after the instance of DuckDB was closed. The potential issues from all these files were starting to mount. This problem didn’t exist when I fired off individual instances of DuckDB because all file locks would be released when I closed DuckDB, but now that I was trying to optimize the process by working with a single instance, it introduced a whole new set of problems.

Worst of all, once I got the chunking process built into the program, the average record lookup time increased to 0.0358 seconds and erased all of the gains I’d seen by simply adding the EXISTS change to the lookup command. And after consulting Claude about these results, Claude suggested several other changes which I made and the time got even worse and was now averaging 0.04745 second per record. We were backing up instead of going forward and clearly “chunking” was not the solution and now, I was drowning in a lake of files.

I’m not sure an AI can get frustrated, but Claude seemed to be grasping at straws too, going back to my question about indexing, Claude suggested adding one to the DuckDB database which I did and saw the database grow from under 1Gb to over 10Gb and the time to build the index slowed the import procedure down significantly. Even with the index in place, the lookups still came in at 0.034 seconds per record and when I reported the disappointing results to Claude, the reply was : “I checked DuckDB’s current documentation on this rather than going from memory, and it turns out I gave you a recommendation that doesn’t fit your actual query shape. The key fact I missed: DuckDB’s ART index does not help joins.”

Holy crap, now even Claude was admitting to having to go back and re-read the documentation! Claude’s honesty was a bit surprising, because I thought it had been reading the documentation all along.

Claude’s frustration (if you can call it that) was fitting in perfectly with the results we’d been getting since the beginning of this project: Solve a problem, Get excited, Discover new problem, Get bummed out, Rinse and Repeat.

But either I’m too stupid to know when to quit, or too optimist I will find a solution because I couldn’t stop. I didn’t know how to get to where I wanted to go and based on Claude’s recommendation to go down this new rabbit hole of creating all these files, I wasn’t confident Claude knew the right next step either. It seemed Claude was responding primarily to the most recent question I posted and maybe didn’t comprehend the 64,000 foot view of what I was really trying to achieve. But somehow, I knew we had come so far, there had to be a light at the end of this rabbit hole.

However, at this point, I starting to feel like I was a fox chasing my tail and it was time to take a break and come back to this again another day.