Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Using vision framework causes grpc-go "panic: Cannot free freed buffer" #277

Open
clarkmcc opened this issue Jan 21, 2025 · 4 comments
Open

Using vision framework causes grpc-go "panic: Cannot free freed buffer" #277

clarkmcc opened this issue Jan 21, 2025 · 4 comments

Comments

@clarkmcc
Copy link

clarkmcc commented Jan 21, 2025 •
edited
Loading

This is a long shot question, but I'm not sure where else to go. I have a grpc-go server that accepts image data, performs OCR using Apple Vision Framework on it, and then returns the results. I've found that sometimes (usually within about 5-10 calls) when I call the following code using the darwinkit library, it triggers a nearly meaningless panic in grpc-go

panic: Cannot free freed buffer

goroutine 31 [running]:
google.golang.org/grpc/mem.(*buffer).Free(0x14000aa8300?)
        /Users/clarkmccauley/go/pkg/mod/google.golang.org/[email protected]/mem/buffers.go:164 +0x12c
google.golang.org/grpc/mem.BufferSlice.Free(...)
        /Users/clarkmccauley/go/pkg/mod/google.golang.org/[email protected]/mem/buffer_slice.go:70
google.golang.org/grpc.(*Server).processUnaryRPC(0x140009c0200, {0x1045e88d0, 0x1400051c960}, 0x14000988ba0, 0x1400051c2a0, 0x1053a8a20, 0x0)
        /Users/clarkmccauley/go/pkg/mod/google.golang.org/[email protected]/server.go:1500 +0x162c
google.golang.org/grpc.(*Server).handleStream(0x140009c0200, {0x1045e9278, 0x1400081a4e0}, 0x14000988ba0)
        /Users/clarkmccauley/go/pkg/mod/google.golang.org/[email protected]/server.go:1802 +0x910
google.golang.org/grpc.(*Server).serveStreams.func2.1()
        /Users/clarkmccauley/go/pkg/mod/google.golang.org/[email protected]/server.go:1030 +0x84
created by google.golang.org/grpc.(*Server).serveStreams.func2 in goroutine 29
        /Users/clarkmccauley/go/pkg/mod/google.golang.org/[email protected]/server.go:1041 +0x13c

I've spent the day isolating the conditions under which this panic appears, and apparently it only appears when I call the objc code attached. Even if I use an entirely different image than what's contained in the grpc-go request's byte slice, I can reliably reproduce this panic, but it only happens after 5-10 calls, meaning the first few calls work just fine. Not calling this code prevents the panic from happening. I've moved this code into a separate thread from the grpc-endpoint to confirm that there wasn't an issue with the autorelease pool locking the OS thread or something, and no luck.

Here is the grpc-go issue: grpc/grpc-go#8023

So my question to darwinkit is: is there anything in here that looks off, that you think could maybe be causing this grpc-go panic?

var out []ExtractedLines
var err error
objc.WithAutoreleasePool(func() {
	handler := vision.NewImageRequestHandler().InitWithDataOptions(r.imageBytes, nil)

	req := vision.NewRecognizeTextRequest().InitWithCompletionHandler(func(request vision.Request, error foundation.Error) {
		if !error.IsNil() {
			err = errors.New(error.Description())
			return
		}

		// Get results and ensure they are handled correctly
		results := objc.Call[foundation.Array](request, objc.Sel("results"))

		// Iterate over results safely
		for _, result := range foundation.ArrayToSlice[objc.Object](results) {
			if objc.Call[bool](result, objc.Sel("isKindOfClass:"), objc.GetClass("VNRecognizedTextObservation")) {
				// Access the boundingBox as foundation.Rect
				boundingBox := objc.Call[foundation.Rect](result, objc.Sel("boundingBox"))

				// Convert Vision's bottom-left origin to top-left origin
				x0 := int(boundingBox.Origin.X * float64(r.width))
				y0 := int((1.0 - (boundingBox.Origin.Y + boundingBox.Size.Height)) * float64(r.height)) // Flip Y-axis
				x1 := int((boundingBox.Origin.X + boundingBox.Size.Width) * float64(r.width))
				y1 := int((1.0 - boundingBox.Origin.Y) * float64(r.height)) // Flip Y-axis

				// Get the recognized text
				recognizedText := objc.Call[foundation.Array](result, objc.Sel("topCandidates:"), 1)
				for _, textCandidate := range foundation.ArrayToSlice[objc.Object](recognizedText) {
					text := objc.Call[string](textCandidate, objc.Sel("string"))

					// Append to the result slice
					out = append(out, ExtractedLines{
						Bounding: [4]int{x0, y0, x1, y1},
						Line:     text,
					})
				}
			}
		}
	})

	req.SetMinimumTextHeight(1 / 100)
	req.SetRecognitionLevel(vision.RequestTextRecognitionLevelAccurate)
	req.SetRecognitionLanguages([]string{"en"})
	req.SetUsesLanguageCorrection(true)
	req.SetCustomWords([]string{"copy", "print", "waiting", "black", "white", "yellow", "magenta", "cyan", "light"})

	var errObj foundation.Error
	handler.PerformRequestsError([]vision.IRequest{req}, unsafe.Pointer(&errObj))
	if !errObj.IsNil() {
		errObj.Autorelease()
		err = errors.New(errObj.Description())
		return
	}
})
@clarkmcc
Copy link
Author

Hm... if I remove this line, it doesn't crash

req.SetUsesLanguageCorrection(true)

@clarkmcc
Copy link
Author

An excerpt of some of the logs (they don't mean much to me) around the crash. I think these logs are only the aftermath, I didn't find any logs regarding the cause. 62752 is the PID of the server running the obj-c.

62752	default	11:49:09.511023-0700	server	-[CREngineAccurate resultDocumentForDetectionResult:image:options:progressHandler:error:]: Form detection is disabled.
62752	default	11:49:09.518093-0700	server	Entering exit handler.
62752	default	11:49:09.518121-0700	server	Queueing exit procedure onto XPC queue. Any further messages sent will be discarded. activeSendTransactions=0
62752	default	11:49:09.518171-0700	server	Cancelling XPC connection. Any further reply handler invocations will not retry messages
62752	default	11:49:09.518183-0700	server	[0x60000006c000] invalidated because the current process cancelled the connection by calling xpc_connection_cancel()
62752	default	11:49:09.518228-0700	server	Exiting exit handler.
62752	default	11:49:09.518218-0700	server	XPC connection invalidated (daemon unloaded/disabled)
442	default	11:49:09.518249-0700	analyticsd	[0x8fcc41040] invalidated because the client process (pid 62752) either cancelled the connection or exited
0	default	11:49:09.518717-0700	kernel	H11ANEInDirectPathClient: clientDied : server (<private>) pid: 62752
0	default	11:49:09.518733-0700	kernel	ANE0: ANE_UserClientCleanup_gated: Releasing program buffer programId: 10 for client server
0	default	11:49:09.518735-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: programHandle: 0xa04a6beeb4b programBufferIndex = 15 referenceCount = 2 releasePendingList=0
0	default	11:49:09.518737-0700	kernel	ANE0: ANE_UserClientCleanup_gated: Releasing program buffer programId: 10 for client server
0	default	11:49:09.518738-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: programHandle: 0xa04a6beeb4b programBufferIndex = 15 referenceCount = 1 releasePendingList=0
0	default	11:49:09.518738-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: Freeing Program buffer -
0	default	11:49:09.518738-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: Model Identifier:
0	default	11:49:09.518739-0700	kernel	
ModelName: 
ModelBundleName: 
ModelPath:
0	default	11:49:09.518740-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: force deiniting program process and program. programHandle: 0xa04a6beeb4b programId: 10 refCount: 1
0	default	11:49:09.518752-0700	kernel	ANE0: ANE_ProcessDestroy_gated: Destroying programHandle: 0xa04a6beeb4b
0	default	11:49:09.519370-0700	kernel	ANE0: FreeSharedMemorySurface: dartUnMapMemoryDescriptorSharedMallocRegion failed
0	default	11:49:09.519673-0700	kernel	ANE0: ANE_ProcessDestroy_gated: WARN: Freeing intermediate buffer freeAll=1 forceDestroy=1
0	default	11:49:09.519680-0700	kernel	ANE0: FreeIntermediateBuffer: Freeing intermediate buffer. intermediateBufferId=0xa04a6cccf7d, size=23052288, dartMapBase=0x00000000319b4000 usage='INTM'
0	default	11:49:09.520098-0700	kernel	ANE0: ANE_ReleasePatchedMutableMemoryBuffer: Patched Mutable buffer is NULL for program
0	default	11:49:09.520780-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: Release vnode iocount: 0 usecount: 4 machoFilePath=/System/Library/PrivateFrameworks/TextRecognition.framework/Resources/cr_orientation_model_v1.mlmodelc.bundle/model.H13.espresso.hwx
0	default	11:49:09.520833-0700	kernel	ANE0: ANE_PowerOff_gated: clientname ISP isPowered 0
0	default	11:49:09.520838-0700	kernel	ANE0: ANE_PowerOff_gated: clientname aned isPowered 1
0	default	11:49:09.520838-0700	kernel	ANE0: ANE_PowerOff_gated: clientname InferenceProvide isPowered 1
0	default	11:49:09.520838-0700	kernel	ANE0: ANE_PowerOff_gated: clientname InferenceProvide isPowered 1
0	default	11:49:09.520839-0700	kernel	ANE0: ANE_PowerOff_gated: clientname InferenceProvide isPowered 1
0	default	11:49:09.520840-0700	kernel	ANE0: ANE_PowerOff_gated: clientname mediaanalysisd isPowered 1
0	default	11:49:09.520842-0700	kernel	ANE0: ANE_PowerOff_gated: clientname mediaanalysisd isPowered 1
0	default	11:49:09.520842-0700	kernel	ANE0: ANE_PowerOff_gated: clientname mediaanalysisd isPowered 1
0	default	11:49:09.520842-0700	kernel	ANE0: ANE_PowerOff_gated: clientname mediaanalysisd isPowered 1
0	default	11:49:09.520843-0700	kernel	ANE0: ANE_PowerOff_gated: clientname mediaanalysisd isPowered 1
0	default	11:49:09.520843-0700	kernel	ANE0: ANE_PowerOff_gated: clientname ___Hub isPowered 1
0	default	11:49:09.520843-0700	kernel	ANE0: ANE_PowerOff_gated: clientname ___Hub isPowered 1
0	default	11:49:09.520844-0700	kernel	ANE0: ANE_PowerOff_gated: clientname ___Hub isPowered 1
0	default	11:49:09.520844-0700	kernel	ANE0: ANE_PowerOff_gated: clientname aomhost isPowered 1
0	default	11:49:09.520845-0700	kernel	ANE0: ANE_PowerOff_gated: clientname aomhost isPowered 1
0	default	11:49:09.520847-0700	kernel	ANE0: ANE_PowerOff_gated: clientname server isPowered 1
0	default	11:49:09.520847-0700	kernel	ANE0: ANE_PowerOff_gated: clientname server isPowered 1
0	default	11:49:09.520848-0700	kernel	ANE0: ANE_PowerOff_gated: clientname server isPowered 1
0	default	11:49:09.520848-0700	kernel	ANE0: ANE_PowerOff_gated: Client requesting power off: server
0	default	11:49:09.520859-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:aned isPowered:1 Programs Open:14 Wired-Memory:277526528 B
0	default	11:49:09.520862-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:InferenceProvide isPowered:1 Programs Open:1 Wired-Memory:7045120 B
0	default	11:49:09.520864-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:InferenceProvide isPowered:1 Programs Open:1 Wired-Memory:3604480 B
0	default	11:49:09.520864-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:InferenceProvide isPowered:1 Programs Open:1 Wired-Memory:589824 B
0	default	11:49:09.520865-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:mediaanalysisd isPowered:1 Programs Open:1 Wired-Memory:448512 B
0	default	11:49:09.520867-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:mediaanalysisd isPowered:1 Programs Open:1 Wired-Memory:448512 B
0	default	11:49:09.520868-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:mediaanalysisd isPowered:1 Programs Open:1 Wired-Memory:47894528 B
0	default	11:49:09.520869-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:mediaanalysisd isPowered:1 Programs Open:1 Wired-Memory:29998080 B
0	default	11:49:09.520870-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:mediaanalysisd isPowered:1 Programs Open:1 Wired-Memory:76038144 B
0	default	11:49:09.520872-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:___Hub isPowered:1 Programs Open:1 Wired-Memory:18433536 B
0	default	11:49:09.520873-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:___Hub isPowered:1 Programs Open:1 Wired-Memory:25776128 B
0	default	11:49:09.520874-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:___Hub isPowered:1 Programs Open:1 Wired-Memory:25792512 B
0	default	11:49:09.520875-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:aomhost isPowered:1 Programs Open:1 Wired-Memory:2998272 B
0	default	11:49:09.520876-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:aomhost isPowered:1 Programs Open:1 Wired-Memory:1294336 B
0	default	11:49:09.520878-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:server isPowered:1 Programs Open:1 Wired-Memory:18433536 B
0	default	11:49:09.520878-0700	kernel	ANE0: ANE_PowerOff_gated: clientname:server isPowered:1 Programs Open:1 Wired-Memory:25776128 B
0	default	11:49:09.520879-0700	kernel	ANE0: ANE_UserClientClose_gated: :
0	default	11:49:09.520883-0700	kernel	ANE0: ANE_UserClientClose_gated: Removing client: <private>, clientName: server
0	default	11:49:09.521012-0700	kernel	H11ANEInDirectPathClient: clientDied : server (<private>) pid: 62752
0	default	11:49:09.521015-0700	kernel	ANE0: ANE_UserClientCleanup_gated: Releasing program buffer programId: 9 for client server
0	default	11:49:09.521017-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: programHandle: 0xa04a6a9c4a5 programBufferIndex = 14 referenceCount = 2 releasePendingList=0
0	default	11:49:09.521018-0700	kernel	ANE0: ANE_UserClientCleanup_gated: Releasing program buffer programId: 9 for client server
0	default	11:49:09.521018-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: programHandle: 0xa04a6a9c4a5 programBufferIndex = 14 referenceCount = 1 releasePendingList=0
0	default	11:49:09.521019-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: Freeing Program buffer -
0	default	11:49:09.521020-0700	kernel	ANE0: ReleaseProgramMemoryBuffer: Model Identifier:

@clarkmcc clarkmcc mentioned this issue Jan 28, 2025
Open
@clarkmcc
Copy link
Author

The consensus from the grpc-go team after investigating was that an unsafe pointer was being incorrectly used and was overwriting a reference counter in the grpc internals. They proved this using a number of tests and then said that the problem was either in my implementation of darwinkit, or within darwinkit itself.

@progrium
Copy link
Owner

progrium commented Jan 29, 2025 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@progrium @clarkmcc