bin/148150: Poor file(1) performance

[Peter Jeremy]

>Number:         148150
>Category:       bin
>Synopsis:       Poor file(1) performance
>Confidential:   no
>Severity:       non-critical
>Priority:       low
>Responsible:    freebsd-bugs
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Fri Jun 25 23:00:09 UTC 2010
>Closed-Date:
>Last-Modified:
>Originator:     Peter Jeremy
>Release:        FreeBSD 8.1-PRERELEASE amd64
>Organization:
n/a
>Environment:
System: FreeBSD server.vk2pj.dyndns.org 8.1-PRERELEASE FreeBSD 8.1-PRERELEASE #4: Sun Jun 13 09:18:30 EST 2010 root at server.vk2pj.dyndns.org:/var/obj/usr/src/sys/server amd64

FreeBSD aspire.vk2pj.dyndns.org 8.1-PRERELEASE FreeBSD 8.1-PRERELEASE #12: Mon Jun 14 11:34:12 EST 2010     root at builder.vk2pj.dyndns.org:/obj/usr/src/sys/aspire  i386

>Description:

	I recently had reason to run file(1) on a large number of
	files and felt the performance wasn't up to par.  When I
	investigated further, I found that about 95% of the runtime
	related to the two regex's to recognize REXX files:

# OS/2 batch files are REXX. the second regex is a bit generic, oh well
# the matched commands seem to be common in REXX and uncommon elsewhere
100	regex/c =3D^[\ \t]{0,10}call[\ \t]{1,10}rxfunc OS/2 REXX batch file text
100	regex/c =3D^[\ \t]{0,10}say\ ['"]	     OS/2 REXX batch file text

	Since REXX files are not present in my environment, I can
	avoid the issue by just commenting out the offending lines.
	Someone with more expertise in magic(5) might be able to
	suggest a better fix.

	I have tried reporting this to the upstream maintainers and
`	received a "not interested" response.

>How-To-Repeat:
	Copy /usr/share/misc/magic to magic.old
	Apply the equivalent of the below patch to create magic.new
	time(1) file(1) on the same set of files using magic.old and magic.new

	Using my home directory on my i386 netbook, I get:
file -m magic.new * > /dev/null  1.42s user 0.13s system 98% cpu 1.576 total
file -m magic.new * > /dev/null  1.35s user 0.10s system 98% cpu 1.469 total
file -m magic.new * > /dev/null  1.35s user 0.10s system 98% cpu 1.470 total
file -m magic.old * > /dev/null  33.35s user 0.11s system 98% cpu 34.055 total
file -m magic.old * > /dev/null  33.12s user 0.14s system 98% cpu 33.714 total
file -m magic.old * > /dev/null  33.08s user 0.11s system 98% cpu 33.606 total

	Using my home directory on my amd64 desktop, I get:
file -m magic.new * > /dev/null  2.18s user 0.41s system 28% cpu 9.111 total
file -m magic.new * > /dev/null  2.11s user 0.49s system 24% cpu 10.707 total
file -m magic.new * > /dev/null  2.05s user 0.56s system 23% cpu 10.989 total
file -m magic.old * > /dev/null  28.54s user 0.51s system 78% cpu 37.088 total
file -m magic.old * > /dev/null  28.54s user 0.52s system 89% cpu 32.575 total
file -m magic.old * > /dev/null  28.71s user 0.47s system 99% cpu 29.371 total

	The poorer wallclock performance on my amd64 is because it's
	running ZFS without adequate RAM whereas my netbook is UFS on SSD
	and the actual directory contents are completely different.
>Fix:

	The following just comments out the REXX test.

Index: Magdir/msdos
===================================================================
RCS file: /usr/ncvs/src/contrib/file/Magdir/msdos,v
retrieving revision 1.3
diff -u -r1.3 msdos
--- Magdir/msdos	4 May 2009 00:37:44 -0000	1.3
+++ Magdir/msdos	19 Jun 2010 03:23:23 -0000
@@ -18,8 +18,8 @@
 
 # OS/2 batch files are REXX. the second regex is a bit generic, oh well
 # the matched commands seem to be common in REXX and uncommon elsewhere
-100	regex/c =^[\ \t]{0,10}call[\ \t]{1,10}rxfunc OS/2 REXX batch file text
-100	regex/c =^[\ \t]{0,10}say\ ['"]	     OS/2 REXX batch file text
+#100	regex/c =^[\ \t]{0,10}call[\ \t]{1,10}rxfunc OS/2 REXX batch file text
+#100	regex/c =^[\ \t]{0,10}say\ ['"]	     OS/2 REXX batch file text
 
 0	leshort		0x14c	MS Windows COFF Intel 80386 object file
 #>4	ledate		x	stamp %s
>Release-Note:
>Audit-Trail:
>Unformatted: