ibm-messaging / mq-golang

Calling IBM MQ from Go applications
Apache License 2.0
168 stars 60 forks source link

Segfault in amqscb #75

Closed joy4eg closed 5 years ago

joy4eg commented 5 years ago

Hey Folks,

Here is the environment information:

$ go version
go version go1.11.4 linux/amd64
$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/userx/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/userx/work/golang"
GOPROXY=""
GORACE=""
GOROOT="/usr/lib/golang"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/golang/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/userx/work/golang/src/github.com/<cut>/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build420169263=/tmp/go-build -gno-record-gcc-switches"
$ gcc --version
gcc (GCC) 8.2.1 20181215 (Red Hat 8.2.1-6)
$ dspmqver
Name:        IBM MQ
Version:     9.1.0.1
Level:       p910-001-181108
BuildType:   IKAP - (Production)
Platform:    IBM MQ for Linux (x86-64 platform)
Mode:        64-bit
O/S:         Linux 4.19.14-300.fc29.x86_64
InstName:    Installation1
InstDesc:    
Primary:     No
InstPath:    /opt/mqm
DataPath:    /var/mqm
MaxCmdLevel: 910

The issue:

Expected result:

Actual result:

Logs:

Sample AMQSCB.GO start
Connected to queue manager QM1
Opened queue DEV.QUEUE.1
signal 11 received but handler not on signal stack
fatal error: non-Go code set up signal handler without SA_ONSTACK flag

runtime stack:
runtime: unexpected return pc for runtime.sigtramp called from 0x7f13cf1aae67
stack: frame={sp:0xc00004e4a8, fp:0xc00004e500} stack=[0xc0000463f8,0xc00004e7f8)
000000c00004e3a8:  000000c00004e3b0  00000000004550d0 <runtime.throw.func1+0> 
000000c00004e3b8:  00000000004e906f  0000000000000039 
000000c00004e3c8:  000000c00004e3e8  000000000044113f <runtime.sigNotOnStack+127> 
000000c00004e3d8:  00000000004e906f  0000000000000039 
000000c00004e3e8:  000000c00004e498  0000000000440974 <runtime.sigtrampgo+788> 
000000c00004e3f8:  000000000000000b  000000c00004e480 
000000c00004e408:  000000c00004e700  0000000000000000 
000000c00004e418:  0000000000000000  000000c00004e4a8 
000000c00004e428:  0000000000000000  0000000000000000 
000000c00004e438:  0000000000000000  0000000000000000 
000000c00004e448:  0000000000000000  000000c000000780 
000000c00004e458:  0000000000000000  0000000000000000 
000000c00004e468:  0000000000000000  0000000000000000 
000000c00004e478:  0000000000000000  000000c000042000 
000000c00004e488:  0000000000000000  0000000000008000 
000000c00004e498:  000000c00004e4f0  000000000045a023 <runtime.sigtramp+67> 
000000c00004e4a8: <000000000000000b  000000c00004e830 
000000c00004e4b8:  000000c00004e700  000000c00004e700 
000000c00004e4c8:  000000c00004e830  0000000000000001 
000000c00004e4d8:  000000000000000b  000000c00004e4f0 
000000c00004e4e8:  00007f13cfb313c0  0000000000f39e20 
000000c00004e4f8: !00007f13cf1aae67 >0000000000000000 
000000c00004e508:  0000000000000000  0000000000000000 
000000c00004e518:  0000000000000000  0000000000000000 
000000c00004e528:  0000000000000000  0000000000000000 
000000c00004e538:  0000000000000000  0000000000000000 
000000c00004e548:  0000000000000000  0000000000000000 
000000c00004e558:  0000000000000000  0000000000000000 
000000c00004e568:  0000000000000000  0000000000000000 
000000c00004e578:  0000000000000000  0000000000000000 
000000c00004e588:  0000000000000000  0000000000000000 
000000c00004e598:  0000000000f39e20  000000c00004edd0 
000000c00004e5a8:  0000000000000008  0000000000000011 
000000c00004e5b8:  00000000004f5654  0000000000000000 
000000c00004e5c8:  00007f13cf1ab665  0000000041534d58 
000000c00004e5d8:  000000000000000b  0000000000000000 
000000c00004e5e8:  0000000000000000  000000c00004e690 
000000c00004e5f8:  0000000000000000 
runtime.throw(0x4e906f, 0x39)
        /usr/lib/golang/src/runtime/panic.go:608 +0x72
runtime.sigNotOnStack(0xb)
        /usr/lib/golang/src/runtime/signal_unix.go:576 +0x7f
runtime.sigtrampgo(0xb, 0xc00004e830, 0xc00004e700)
        /usr/lib/golang/src/runtime/signal_unix.go:334 +0x314
runtime: unexpected return pc for runtime.sigtramp called from 0x7f13cf1aae67
stack: frame={sp:0xc00004e4a8, fp:0xc00004e500} stack=[0xc0000463f8,0xc00004e7f8)
000000c00004e3a8:  000000c00004e3b0  00000000004550d0 <runtime.throw.func1+0> 
000000c00004e3b8:  00000000004e906f  0000000000000039 
000000c00004e3c8:  000000c00004e3e8  000000000044113f <runtime.sigNotOnStack+127> 
000000c00004e3d8:  00000000004e906f  0000000000000039 
000000c00004e3e8:  000000c00004e498  0000000000440974 <runtime.sigtrampgo+788> 
000000c00004e3f8:  000000000000000b  000000c00004e480 
000000c00004e408:  000000c00004e700  0000000000000000 
000000c00004e418:  0000000000000000  000000c00004e4a8 
000000c00004e428:  0000000000000000  0000000000000000 
000000c00004e438:  0000000000000000  0000000000000000 
000000c00004e448:  0000000000000000  000000c000000780 
000000c00004e458:  0000000000000000  0000000000000000 
000000c00004e468:  0000000000000000  0000000000000000 
000000c00004e478:  0000000000000000  000000c000042000 
000000c00004e488:  0000000000000000  0000000000008000 
000000c00004e498:  000000c00004e4f0  000000000045a023 <runtime.sigtramp+67> 
000000c00004e4a8: <000000000000000b  000000c00004e830 
000000c00004e4b8:  000000c00004e700  000000c00004e700 
000000c00004e4c8:  000000c00004e830  0000000000000001 
000000c00004e4d8:  000000000000000b  000000c00004e4f0 
000000c00004e4e8:  00007f13cfb313c0  0000000000f39e20 
000000c00004e4f8: !00007f13cf1aae67 >0000000000000000 
000000c00004e508:  0000000000000000  0000000000000000 
000000c00004e518:  0000000000000000  0000000000000000 
000000c00004e528:  0000000000000000  0000000000000000 
000000c00004e538:  0000000000000000  0000000000000000 
000000c00004e548:  0000000000000000  0000000000000000 
000000c00004e558:  0000000000000000  0000000000000000 
000000c00004e568:  0000000000000000  0000000000000000 
000000c00004e578:  0000000000000000  0000000000000000 
000000c00004e588:  0000000000000000  0000000000000000 
000000c00004e598:  0000000000f39e20  000000c00004edd0 
000000c00004e5a8:  0000000000000008  0000000000000011 
000000c00004e5b8:  00000000004f5654  0000000000000000 
000000c00004e5c8:  00007f13cf1ab665  0000000041534d58 
000000c00004e5d8:  000000000000000b  0000000000000000 
000000c00004e5e8:  0000000000000000  000000c00004e690 
000000c00004e5f8:  0000000000000000 
runtime.sigtramp(0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /usr/lib/golang/src/runtime/sys_linux_amd64.s:353 +0x43

goroutine 34 [syscall, locked to thread]:
runtime.goexit()
        /usr/lib/golang/src/runtime/asm_amd64.s:1333 +0x1 fp=0xc0000cefe8 sp=0xc0000cefe0 pc=0x458441

goroutine 1 [sleep]:
fatal error: unexpected signal during runtime execution
panic during panic
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x44d78b]

runtime stack:
runtime: unexpected return pc for runtime.sigtramp called from 0x7f13cf1aae67
stack: frame={sp:0xc00004e4a8, fp:0xc00004e500} stack=[0xc0000463f8,0xc00004e7f8)
000000c00004e3a8:  000000c00004e3b0  00000000004550d0 <runtime.throw.func1+0> 
000000c00004e3b8:  00000000004e906f  0000000000000039 
000000c00004e3c8:  000000c00004e3e8  000000000044113f <runtime.sigNotOnStack+127> 
000000c00004e3d8:  00000000004e906f  0000000000000039 
000000c00004e3e8:  000000c00004e498  0000000000440974 <runtime.sigtrampgo+788> 
000000c00004e3f8:  000000000000000b  000000c00004e480 
000000c00004e408:  000000c00004e700  0000000000000000 
000000c00004e418:  0000000000000000  000000c00004e4a8 
000000c00004e428:  0000000000000000  0000000000000000 
000000c00004e438:  0000000000000000  0000000000000000 
000000c00004e448:  0000000000000000  000000c000000780 
000000c00004e458:  0000000000000000  0000000000000000 
000000c00004e468:  0000000000000000  0000000000000000 
000000c00004e478:  0000000000000000  000000c000042000 
000000c00004e488:  0000000000000000  0000000000008000 
000000c00004e498:  000000c00004e4f0  000000000045a023 <runtime.sigtramp+67> 
000000c00004e4a8: <000000000000000b  000000c00004e830 
000000c00004e4b8:  000000c00004e700  000000c00004e700 
000000c00004e4c8:  000000c00004e830  0000000000000001 
000000c00004e4d8:  000000000000000b  000000c00004e4f0 
000000c00004e4e8:  00007f13cfb313c0  0000000000f39e20 
000000c00004e4f8: !00007f13cf1aae67 >0000000000000000 
000000c00004e508:  0000000000000000  0000000000000000 
000000c00004e518:  0000000000000000  0000000000000000 
000000c00004e528:  0000000000000000  0000000000000000 
000000c00004e538:  0000000000000000  0000000000000000 
000000c00004e548:  0000000000000000  0000000000000000 
000000c00004e558:  0000000000000000  0000000000000000 
000000c00004e568:  0000000000000000  0000000000000000 
000000c00004e578:  0000000000000000  0000000000000000 
000000c00004e588:  0000000000000000  0000000000000000 
000000c00004e598:  0000000000f39e20  000000c00004edd0 
000000c00004e5a8:  0000000000000008  0000000000000011 
000000c00004e5b8:  00000000004f5654  0000000000000000 
000000c00004e5c8:  00007f13cf1ab665  0000000041534d58 
000000c00004e5d8:  000000000000000b  0000000000000000 
000000c00004e5e8:  0000000000000000  000000c00004e690 
000000c00004e5f8:  0000000000000000 
runtime.throw(0x4e831b, 0x2a)
        /usr/lib/golang/src/runtime/panic.go:608 +0x72
runtime.sigpanic()
        /usr/lib/golang/src/runtime/signal_unix.go:374 +0x2f2
runtime.gentraceback(0xffffffffffffffff, 0xffffffffffffffff, 0x0, 0xc000000300, 0x0, 0x0, 0x64, 0x0, 0x0, 0x0, ...)
        /usr/lib/golang/src/runtime/traceback.go:249 +0x155b
runtime.traceback1(0xffffffffffffffff, 0xffffffffffffffff, 0x0, 0xc000000300, 0x0)
        /usr/lib/golang/src/runtime/traceback.go:728 +0xf3
runtime.traceback(0xffffffffffffffff, 0xffffffffffffffff, 0x0, 0xc000000300)
        /usr/lib/golang/src/runtime/traceback.go:682 +0x52
runtime.tracebackothers(0xc0000be180)
        /usr/lib/golang/src/runtime/traceback.go:947 +0x187
runtime.dopanic_m(0xc0000be180, 0x42de02, 0xc00004e3a8, 0x1)
        /usr/lib/golang/src/runtime/panic.go:805 +0x2aa
runtime.fatalthrow.func1()
        /usr/lib/golang/src/runtime/panic.go:663 +0x5f
runtime.fatalthrow()
        /usr/lib/golang/src/runtime/panic.go:660 +0x57
runtime.throw(0x4e906f, 0x39)
        /usr/lib/golang/src/runtime/panic.go:608 +0x72
runtime.sigNotOnStack(0xb)
        /usr/lib/golang/src/runtime/signal_unix.go:576 +0x7f
runtime.sigtrampgo(0xb, 0xc00004e830, 0xc00004e700)
        /usr/lib/golang/src/runtime/signal_unix.go:334 +0x314
runtime: unexpected return pc for runtime.sigtramp called from 0x7f13cf1aae67
stack: frame={sp:0xc00004e4a8, fp:0xc00004e500} stack=[0xc0000463f8,0xc00004e7f8)
000000c00004e3a8:  000000c00004e3b0  00000000004550d0 <runtime.throw.func1+0> 
000000c00004e3b8:  00000000004e906f  0000000000000039 
000000c00004e3c8:  000000c00004e3e8  000000000044113f <runtime.sigNotOnStack+127> 
000000c00004e3d8:  00000000004e906f  0000000000000039 
000000c00004e3e8:  000000c00004e498  0000000000440974 <runtime.sigtrampgo+788> 
000000c00004e3f8:  000000000000000b  000000c00004e480 
000000c00004e408:  000000c00004e700  0000000000000000 
000000c00004e418:  0000000000000000  000000c00004e4a8 
000000c00004e428:  0000000000000000  0000000000000000 
000000c00004e438:  0000000000000000  0000000000000000 
000000c00004e448:  0000000000000000  000000c000000780 
000000c00004e458:  0000000000000000  0000000000000000 
000000c00004e468:  0000000000000000  0000000000000000 
000000c00004e478:  0000000000000000  000000c000042000 
000000c00004e488:  0000000000000000  0000000000008000 
000000c00004e498:  000000c00004e4f0  000000000045a023 <runtime.sigtramp+67> 
000000c00004e4a8: <000000000000000b  000000c00004e830 
000000c00004e4b8:  000000c00004e700  000000c00004e700 
000000c00004e4c8:  000000c00004e830  0000000000000001 
000000c00004e4d8:  000000000000000b  000000c00004e4f0 
000000c00004e4e8:  00007f13cfb313c0  0000000000f39e20 
000000c00004e4f8: !00007f13cf1aae67 >0000000000000000 
000000c00004e508:  0000000000000000  0000000000000000 
000000c00004e518:  0000000000000000  0000000000000000 
000000c00004e528:  0000000000000000  0000000000000000 
000000c00004e538:  0000000000000000  0000000000000000 
000000c00004e548:  0000000000000000  0000000000000000 
000000c00004e558:  0000000000000000  0000000000000000 
000000c00004e568:  0000000000000000  0000000000000000 
000000c00004e578:  0000000000000000  0000000000000000 
000000c00004e588:  0000000000000000  0000000000000000 
000000c00004e598:  0000000000f39e20  000000c00004edd0 
000000c00004e5a8:  0000000000000008  0000000000000011 
000000c00004e5b8:  00000000004f5654  0000000000000000 
000000c00004e5c8:  00007f13cf1ab665  0000000041534d58 
000000c00004e5d8:  000000000000000b  0000000000000000 
000000c00004e5e8:  0000000000000000  000000c00004e690 
000000c00004e5f8:  0000000000000000 
runtime.sigtramp(0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /usr/lib/golang/src/runtime/sys_linux_amd64.s:353 +0x43
ibmmqmet commented 5 years ago

Not really enough to diagnose from here. There's no indication of where the problem occurred, not even a stack trace with function names.

Perhaps an MQ trace, if the error is actually happening in the MQ libraries. Or something in the MQ error logs or FDC files. Or running it under a debugger to trap the SEGV would show it.

joy4eg commented 5 years ago

Looks like we have NULL pointer dereference here:

Thread 8 "amqscb" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffd3055700 (LWP 31116)]
0x0000000000493c06 in github.com/ibm-messaging/mq-golang/ibmmq.copyGMOfromC (gogmo=0xc0000c2000, mqgmo=0x0) at /home/userx/work/golang/pkg/mod/github.com/ibm-messaging/mq-golang@v3.3.3+incompatible/ibmmq/mqiMQGMO.go:110
110             gogmo.Version = int32(mqgmo.Version)
(gdb) bt
#0  0x0000000000493c06 in github.com/ibm-messaging/mq-golang/ibmmq.copyGMOfromC (gogmo=0xc0000c2000, mqgmo=0x0) at /home/userx/work/golang/pkg/mod/github.com/ibm-messaging/mq-golang@v3.3.3+incompatible/ibmmq/mqiMQGMO.go:110
#1  0x0000000000495812 in github.com/ibm-messaging/mq-golang/ibmmq.MQCALLBACK_Go (hConn=<optimized out>, mqBuffer=<optimized out>, mqcbc=<optimized out>, mqgmo=0x0, mqmd=<optimized out>)
    at /home/userx/work/golang/pkg/mod/github.com/ibm-messaging/mq-golang@v3.3.3+incompatible/ibmmq/mqicb.go:72
#2  0x0000000000491f61 in github.com/ibm-messaging/mq-golang/ibmmq._cgoexpwrap_4f43e2784329_MQCALLBACK_Go (p0=<optimized out>, p1=<optimized out>, p2=<optimized out>, p3=<optimized out>, p4=<optimized out>)
    at _cgo_gotypes.go:1581
#3  0x00000000004567ab in runtime.call64 () at /usr/lib/golang/src/runtime/asm_amd64.s:523
#4  0x000000000040901b in runtime.cgocallbackg1 (ctxt=0) at /usr/lib/golang/src/runtime/cgocall.go:313
#5  0x0000000000408de6 in runtime.cgocallbackg (ctxt=0) at /usr/lib/golang/src/runtime/cgocall.go:191
#6  0x0000000000457cfb in runtime.cgocallback_gofunc () at /usr/lib/golang/src/runtime/asm_amd64.s:775
#7  0x0000000000458441 in runtime.goexit () at /usr/lib/golang/src/runtime/asm_amd64.s:1333
#8  0x0000000000000000 in ?? ()

For some reason mqgmo that came from C code (if I understand correctly) is NULL.

joy4eg commented 5 years ago
Thread 8 "amqscb" hit Breakpoint 1, MQCALLBACK_Go (p0=16777221, p1=0x0, p2=0x0, p3=0x0, p4=0x628010) at _cgo_export.c:23
23      _cgo_export.c: Нет такого файла или каталога.
(gdb) p p4
$1 = (MQCBC *) 0x628010
(gdb) p *p4
$3 = {
  StrucId = "CBC ", 
  Version = 1, 
  CallType = 5, 
  Hobj = 0, 
  CallbackArea = 0x0, 
  ConnectionArea = 0x0, 
  CompCode = 2, 
  Reason = 2033, 
  State = 0, 
  DataLength = 0, 
  BufferLength = 0, 
  Flags = 0, 
  ReconnectDelay = 0
}

Also I have tried to make breakpoint at ibmmq._cgoexpwrap_4f43e2784329_MQCALLBACK_Go but it was useless because all arguments are optimized. Hope this was helpful.

joy4eg commented 5 years ago

Looks like Reason = 2033 it's MQRC_NO_MSG_AVAILABLE, which make sense, because default timeout for waiting for a new messages is 3sec and application also crashes in this time.

So we can just add additional check, that mqmd, mqgmo, mqBuffer are NOT NULL, because, as I see, they are NULL if we are trying to prepare data to invoke user callback when no message was received.

ibmmqmet commented 5 years ago

thanks for the trace. I can see what's going on. It's not quite as simple as testing for NULL though. It appears that the client connections are behaving differently than local connections for 2033 timeouts - the CallType in the CBC indicates an EVENT rather than MESSAGE. I'm not certain that's how it's meant to behave, but it does ... I'll need to look deeper into the underlying MQ libraries to see what's going on there. Feels like a bug.

And in the meantime, that event that is not associated with an hObj is leading to the sample program not ending correctly as there's no handler registered for it, which will need to be dealt with somehow.

joy4eg commented 5 years ago

the CallType in the CBC indicates an EVENT rather than MESSAGE.

From my point of view, it make sense, because we don't have any message to process.

Anyway, thanks for the help and investigations. Feel free to ping me if you will need to do some more testing/debugging :)

joy4eg commented 5 years ago

Have tested with fb10f45792754c5fd85af2d46bde27485da5a4ea and now it works fine, thanks! I guess you can close the issue and create please a new release.

Thank you!