Massive Zero-Padded Quickbooks Files and Explorer.exe crases

[soapee01]

I'm seeing Quickbooks files that are normally 10's of megabytes in size at a CPA firm that are getting zero-padded up to 16TB in file size. I wrote a script that fixes these files, and so far, I've found 6 quickbooks files with the issue. I need to optimize the script to scan the thousands of QBW files they have, so until then I called it with find looking for files larger than 1GB.

Code:

find /mnt/pool1/share -type f -size +1G

The script does verify that these are zero-padded at the end.

Additional behavior I'm seeing for about half of the users is that explorer.exe will crash on their PCs. I was finally able to see this, and it happens just scrolling through a directory window. It doesn't even have to be one of the directories with files that I've found issues with.

I've run AV scans with webroot and MalwareBytes Techbench on the users' PCs, and on the TrueNAS share. Nothing was found.

This morning I was looking over the unifi controller panel to figure out what's causing this and see if the two issues are related. I found one PC communicating with TrueNAS and saturating the gigbabit network. I expected that it was quickbooks trying to write more zero-padded files, but in this case it was TrueNAS sending data to the client PC. I'm guessing that she'd tried to open it yesterday. Here's some images that show the network issues. I tried killing the quickbooks process on her PC (didn't work) and gracefully restarting (also didn't work). I had to hard power off the PC and turn it on again. That's where you can see the graphs on network usage dip down to normal.

This is what I could see in task manager on her PC this morning.

I cannot find any network errors, nor have I found anything useful in the TrueNAS logs, nor in the windows logs. TrueNAS doesn't show anything abnormal in the Samba logs (or /var/log/messages), and windows only shows that explorer.exe crashed with a generic error.

I don't seem to be seeing any NIC errors that I can find. I'm more linux knowlegable than FreeBSD; but this is what I could discern without ethtool

Code:

# netstat -ibh
Name    Mtu Network       Address              Ipkts Ierrs Idrop     Ibytes    Opkts Oerrs     Obytes  Coll
igb0   1.5K <Link#1>      d0:50:99:c3:9d:20      12G     0     0        17T     1.3G     0       1.4T     0
igb0      - 192.168.1.0/2 192.168.1.51          1.5G     -     -        16T     2.2G     -       1.4T     -

A few days ago when I was able to watch explorer.exe crash repeatedly by in the directory window (explorer.exe). I screenshot the event viewer.

Here's some more information about the files:

Code:

find ./ -type f -size +1G -exec ls -alh {} \;
-r-xrwxr-x+ 1 CONTOSO\user  CONTOSO\domain users    16T Sep 30 09:32 /mnt/pool/SHARE/QB CLIENTS/Spacely Sprockets/Company File.qbw

Here's the actual disk usage. ZFS compression is saving us here...

Code:

# du -cksh /mnt/pool/SHARE/QB CLIENTS/Spacely Sprockets/Company File.qbw
13M   /mnt/pool/SHARE/QB CLIENTS/Spacely Sprockets/Company File.qbw

Here's some hexdump info to show the zero padding. I'm pulling the first 25MB of the file, feeding that through hexdump and showing the last 10 lines...

Code:

# head -c 26214400 "/mnt/pool/SHARE/QB CLIENTS/Spacely Sprockets/Company File.qbw" | hexdump -C |tail -n 10
012daf90  bc 83 27 ee 92 36 fd a1  68 0c b0 77 1b e2 86 4d  |..'..6..h..w...M|
012dafa0  f1 95 5c 00 c7 6b 0f d6  7a 41 e5 89 50 f4 bb 5f  |..\..k..zA..P.._|
012dafb0  26 ca 6e 35 d9 a0 44 e8  af 53 1a be 62 29 cd 94  |&.n5..D..S..b)..|
012dafc0  38 ff a3 47 0e b2 79 1d  c1 88 2c f3 97 3b 02 a6  |8..G..y...,..;..|
012dafd0  6d 11 d8 7c 20 e7 8b 52  f6 9a 61 05 cc 70 14 db  |m..| ..R..a..p..|
012dafe0  7f 46 ea b1 55 f9 c0 64  2b cf 73 3a de a5 49 ed  |.F..U..d+.s:..I.|
012daff0  00 00 68 00 f0 80 04 00  00 00 00 00 a4 ba 25 39  |..h...........%9|
012db000  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
*
01900000

Does anyone have any ideas as to what might be causing this, or where to poke around next?

Does quickbooks no longer play nicely with SAMBA? This system has been running fine for years. I upgraded from FreeNAS to TrueNAS 12.0-U8.1 (FREENAS-MINI-2.0) but that didn't resolve it. I know ONE of the files is quickbooks 2021. I'm not sure of the rest. They use every version of quickbooks from 2013 to current. I'll try and find out what versions of quickbooks are used on the other affected files. In my head it's possible that its a bug with intuit/samba that started in 2021, but I don't know with any certainty.

I really appreciate any pointers you have!

Thanks

 

[soapee01]

Sigh, the images got downsized. The explorer.exe error in the event viewer was:

Faulting application name: explorer.exe, version: 10.0.19041.1889, time stamp: 0xd1439b88
Faulting module name: ntdll.dll, version 10.0.19041.1806,
Exception code: 0xc0000374
Fault offset: 0x0000000000ff609
Faulting application path: C:\WINDOWS\explorer.exe
Faulting module path: C:\WINDOWS\SYSTEM32\ntdll.dll

 

[Ericloewe]

The only thing I can think of is Quickbooks going crazy trying to use available space (Because reasons? Maybe it mistook free space for extra money to be sucked dry from customers...). With compression, the extra zeros would compress down to nearly nothing, allowing the files to grow to monstrous logical sizes.

 

[anodos]

What is ls -lo for one of the files in question?

Actually scratch that. I wonder if quickbooks is basically doing ftruncate over SMB to set some crazy file size.

Code:

        DEBUG(10,("vfs_allocate_file_space: file %s, len %.0f\n",
                  fsp_str_dbg(fsp), (double)len));

You can set the auxiliary parameter under services->SMB
"log level = 1 vfs:10" and grep for above string (if you can set up a test server in a VM)... I wouldn't turn up logging that high on a production server.

 

[soapee01]

What is ls -lo for one of the files in question?

Actually scratch that. I wonder if quickbooks is basically doing ftruncate over SMB to set some crazy file size.

Code:

        DEBUG(10,("vfs_allocate_file_space: file %s, len %.0f\n",
                  fsp_str_dbg(fsp), (double)len));

You can set the auxiliary parameter under services->SMB
"log level = 1 vfs:10" and grep for above string (if you can set up a test server in a VM)... I wouldn't turn up logging that high on a production server.

I haven't been able to replicate this, so setting it up on a test machine would be difficult to show anything, as well as getting the users to actually do so (it's tax season...).

How busy is the logfile, and will it affect samba performance much? Hopefully freenas will allow me to change the logfile location to a dataset for this. Drives are 3.5" WDC WD3001FFSX-68JNUN0 (WD Red Pro 3TB 7200RPM) in a raid 10 (ZFS) configuration. There's no l2arc/zil on this box. I'm willing to turn it on in production if it helps solve the issues. EDIT: I can also talk to the users about adding a PCIe card to the box and an nvme drive for logging, but they probably won't allow me to do so until after tax deadlines are over.


I'm waiting on confirmation from the users as well that the script fixes their files, and I want to know if there's any correlation between the broken files and quickbooks versions.

Thanks for the info!

 

[soapee01]

The only thing I can think of is Quickbooks going crazy trying to use available space (Because reasons? Maybe it mistook free space for extra money to be sucked dry from customers...). With compression, the extra zeros would compress down to nearly nothing, allowing the files to grow to monstrous logical sizes.

Ha! Yeah, I think we're hitting an error with Quickbooks, and something that isn't caught by samba/freenas. It's strange to be sure. I cannot find another case like it anywhere.

I probably need to check other files on the system as well for zero padding, but they aren't showing up as massive files.

 

[anodos]

Zeros aren't really that surprising if quickbooks is explicitly setting the filesize to something large. Consider following simple example:

Code:

>>> import os
>>> fd = os.open('/tmp/foo', os.O_RDWR)
>>> os.fstat(fd).st_size
5
>>> os.ftruncate(fd, 1024)
>>> os.fsync(fd)
>>> os.fstat(fd).st_size
1024
>>> os.pread(fd, 100, 6)
b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'

This is why I mentioned the ftruncate. In theory you could probably catch it with a short dtrace script if you're familiar with it.

For example:

Code:

#!/usr/sbin/dtrace -s

syscall::ftruncate:entry

/execname=="smbd" && arg1 > 0/
{
@[ustack(),probefunc] = count();
}

Something like that should aggregate ftruncate calls from smbd based on their stack. Above catches if bytes for ftruncate call > 0, obviously you can filter for higher values.

 

[winnielinnie]

A nightmare continuation from here?

Massive Files (TB) that have small size on disk

I'm not sure if this is a FreeNAS (11.2-U8) issue or a QuickBooks issue, but I've got some files that show up as 3.25TB in windows (and ls on freenas) but size on disk shows 8MB in windows. ZFS does not show that much storage space used. I'm using rsync to copy this across to another backup...

www.truenas.com

Did you ever find out why QuickBooks does that over SMB shares?

To this day, I'm still baffled by this.

Zeros aren't really that surprising if quickbooks is explicitly setting the filesize to something large.

If you read the previous thread (linked above), I don't see any sane reason why QuickBooks would explicitly set a single file to be 3.3 TB in size.