Bug 1740413 - Gluster volume bricks crashes when running a security scan on glusterfs ports
Summary: Gluster volume bricks crashes when running a security scan on glusterfs ports
Keywords:
Status: CLOSED DUPLICATE of bug 1749625
Alias: None
Product: GlusterFS
Classification: Community
Component: rpc
Version: 6
Hardware: x86_64
OS: Linux
high
high
Target Milestone: ---
Assignee: bugs@gluster.org
QA Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-08-12 21:21 UTC by Marvin
Modified: 2020-01-27 10:25 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-01-27 10:25:21 UTC
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:


Attachments (Terms of Use)
GlusterFS brick crash during nexpose scan (2.89 KB, text/plain)
2019-10-04 04:06 UTC, Cybergavin
no flags Details

Description Marvin 2019-08-12 21:21:54 UTC
Description of problem:
I have a gluster cluster (three nodes) replica configuration. Every time the security team runs a security scans on the gluster ports, the bricks crashes. This is what I can see in the brick log:

[2019-07-30 22:36:03.272400] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 33554948 is serviced using standard calloc() (0x7fb724004340) as it exceeds the maximum available buffer size
[2019-07-30 22:36:03.272441] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (1903518060) received from 10.7.1.111:44003
[2019-07-30 22:36:03.272455] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:18) (non-SSL)
[2019-07-30 22:36:03.273756] D [logging.c:2006:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
[2019-07-30 22:36:03.272462] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb724004340) allocated with standard calloc()
[2019-07-30 22:36:03.273753] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 16777220 is serviced using standard calloc() (0x7fb724004340) as it exceeds the maximum available buffer size
[2019-07-30 22:36:11.273537] D [socket.c:692:__socket_rwv] 0-tcp.shared-server: EOF on socket 18 (errno:11:Resource temporarily unavailable); returning ENODATA
[2019-07-30 22:36:11.273588] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:18) (non-SSL)
[2019-07-30 22:36:11.273617] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb724004340) allocated with standard calloc()
[2019-07-30 22:36:11.274164] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:18) (non-SSL)
[2019-07-30 22:36:11.274192] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:-1) (non-SSL)
[2019-07-30 22:36:11.274266] E [socket.c:1303:socket_event_poll_err] (-->/lib64/libglusterfs.so.0(+0x8c286) [0x7fb743df6286] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0xa48a) [0x7fb73815548a] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0x81fc) [0x7fb7381531fc] ) 0-socket: invalid argument: this->private [Invalid argument]
[2019-07-30 22:36:11.276001] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 1010792561 is serviced using standard calloc() (0x7fb7280916d0) as it exceeds the maximum available buffer size
[2019-07-30 22:36:11.276043] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (1920166255) received from 10.7.1.111:46889
[2019-07-30 22:36:11.276067] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:18) (non-SSL)
[2019-07-30 22:36:11.276086] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb7280916d0) allocated with standard calloc()
[2019-07-30 22:36:11.278384] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 83888900 is serviced using standard calloc() (0x7fb7280916d0) as it exceeds the maximum available buffer size
[2019-07-30 22:36:11.278408] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (2113940992) received from 10.7.1.111:46893
[2019-07-30 22:36:11.278419] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:18) (non-SSL)
[2019-07-30 22:36:11.278425] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb7280916d0) allocated with standard calloc()
[2019-07-30 22:36:11.280615] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 35913732 is serviced using standard calloc() (0x7fb7280916d0) as it exceeds the maximum available buffer size
[2019-07-30 22:36:11.280641] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (402784256) received from 10.7.1.111:46894
[2019-07-30 22:36:11.280652] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:18) (non-SSL)
[2019-07-30 22:36:11.280658] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb7280916d0) allocated with standard calloc()
[2019-07-30 22:36:11.282022] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:18) (non-SSL)
[2019-07-30 22:36:11.282077] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:-1) (non-SSL)
[2019-07-30 22:36:11.282106] D [logging.c:1813:gf_log_flush_extra_msgs] 0-logging-infra: Log buffer size reduced. About to flush 5 extra log messages
The message "D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295622 is serviced using standard calloc() (0x7fb724004340) as it exceeds the maximum available buffer size" repeated 3 times between [2019-07-30 22:35:31.388217] and [2019-07-30 22:35:31.393899]
The message "D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295620 is serviced using standard calloc() (0x7fb724004340) as it exceeds the maximum available buffer size" repeated 4 times between [2019-07-30 22:35:31.386015] and [2019-07-30 22:35:31.403951]
[2019-07-30 22:36:11.282153] D [logging.c:1816:gf_log_flush_extra_msgs] 0-logging-infra: Just flushed 5 extra log messages
pending frames:
patchset: git://git.gluster.org/glusterfs.git
signal received: 11
time of crash:
2019-07-30 22:36:11
configuration details:
argp 1
backtrace 1
dlfcn 1
libpthread 1
llistxattr 1
setfsid 1
spinlock 1
[2019-07-30 22:36:11.282148] E [socket.c:1303:socket_event_poll_err] (-->/lib64/libglusterfs.so.0(+0x8c286) [0x7fb743df6286] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0xa48a) [0x7fb73815548a] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0x81fc) [0x7fb7381531fc] ) 0-socket: invalid argument: this->private [Invalid argument]
epoll.h 1
xattr.h 1
st_atim.tv_nsec 1
package-string: glusterfs 6.1
/lib64/libglusterfs.so.0(+0x26db0)[0x7fb743d90db0]
/lib64/libglusterfs.so.0(gf_print_trace+0x334)[0x7fb743d9b7b4]
/lib64/libc.so.6(+0x36280)[0x7fb7423d0280]
/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0xa4cc)[0x7fb7381554cc]
/lib64/libglusterfs.so.0(+0x8c286)[0x7fb743df6286]
/lib64/libpthread.so.0(+0x7dd5)[0x7fb742bd0dd5]
/lib64/libc.so.6(clone+0x6d)[0x7fb742497ead]
---------  

Version-Release number of selected component (if applicable):

# uname -r
4.17.4-1.el7.elrepo.x86_64

# rpm -qa | grep gluster
nfs-ganesha-gluster-2.7.4-1.el7.x86_64
glusterfs-fuse-6.1-1.el7.x86_64
glusterfs-libs-6.1-1.el7.x86_64
glusterfs-6.1-1.el7.x86_64
glusterfs-client-xlators-6.1-1.el7.x86_64
glusterfs-api-6.1-1.el7.x86_64
glusterfs-server-6.1-1.el7.x86_64
glusterfs-cli-6.1-1.el7.x86_64

Running a volume status shows:

Status of volume: shared
Gluster process                             TCP Port  RDMA Port  Online  Pid
------------------------------------------------------------------------------
Brick gfs004:/opt/data/shared               N/A       N/A        N       N/A  
Brick gfs005:/opt/data/shared               N/A       N/A        N       N/A  
Brick gfs006:/opt/data/shared               N/A       N/A        N       N/A  
Self-heal Daemon on localhost               N/A       N/A        Y       57760
Self-heal Daemon on gfs005                  N/A       N/A        Y       24010
Self-heal Daemon on gfs004                  N/A       N/A        Y       65192
 
Task Status of Volume shared
------------------------------------------------------------------------------
There are no active volume tasks

How reproducible:

Steps to Reproduce:
1. Create a three hosts cluster with replicated data
2. Start a volume
3. Run a security scan
4. Bricks should be crashed

Actual results:
Brick process crashes

Expected results:
Brick should ignore the scan and continue running.


Additional info:

Comment 2 Amar Tumballi 2019-08-13 05:48:25 UTC
Looks like the bits are for Upstream GlusterFS (based on the version). Moving the product to 'GlusterFS'. Will analyze this.

> Every time the security team runs a security scans on the gluster ports, the bricks crashes.

When you say security scan, is it nmap with arguments, or other scripts too? Also is it possible to set 'gluster volume set VOLNAME brick-log-level TRACE' before the test, and run the scan ? That would help us to get more details.

Comment 3 Marvin 2019-08-16 15:44:42 UTC
Hello, sorry for the delay on providing this log. I still don't have more information about the scripts used on the security scan but I will provide it as soon as I get it from the security team. Thank you for your help.

Brick log with TRACE log level enabled (Part 1):
[2019-08-04 10:24:04.372080] T [MSGID: 0] [posix.c:4388:pl_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-locks to shared-access-control
[2019-08-04 10:24:04.372096] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-access-control to shared-bitrot-stub
[2019-08-04 10:24:04.372110] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-bitrot-stub to shared-changelog
[2019-08-04 10:24:04.372136] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-changelog to shared-trash
[2019-08-04 10:24:04.372150] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-trash to shared-posix
[2019-08-04 10:24:04.372211] T [MSGID: 0] [posix-inode-fd-ops.c:2287:posix_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-posix returned 0
[2019-08-04 10:24:04.372228] T [MSGID: 0] [posix.c:4379:pl_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-locks returned 0
[2019-08-04 10:24:04.372242] T [MSGID: 0] [upcall.c:1211:up_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-upcall returned 0
[2019-08-04 10:24:04.372255] T [MSGID: 0] [defaults.c:1642:default_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-io-threads returned 0
[2019-08-04 10:24:04.372282] T [rpcsvc.c:1533:rpcsvc_submit_generic] 0-rpc-service: Tx message: 108
[2019-08-04 10:24:04.372298] T [rpcsvc.c:1069:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 132, payload: 108, rpc hdr: 24
[2019-08-04 10:24:04.372348] T [rpcsvc.c:1585:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x1d89a, Program: GlusterFS 4.x v1, ProgVers: 400, Proc: 14) to rpc-transport (tcp.shared-server)
[2019-08-04 10:24:04.372436] D [client_t.c:433:gf_client_unref] (-->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x5afc3) [0x7fb1c2a7efc3] -->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0xadeb) [0x7fb1c2a2edeb] -->/lib64/libglusterfs.so.0(gf_client_unref+0x7b) [0x7fb1d7b0fd2b] ) 0-client_t: CTX_ID:ca89ac1a-1d4d-4aea-b264-fce7b1378aa4-GRAPH_ID:2-PID:22025-HOST:gfs-migration701-PC_NAME:shared-client-1-RECON_NO:-2: ref-count 1
[2019-08-04 10:24:14.266296] D [logging.c:2006:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
[2019-08-04 10:24:04.372271] T [MSGID: 0] [io-stats.c:2354:io_stats_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-io-stats returned 0
[2019-08-04 10:24:14.266290] T [MSGID: 0] [posix-helpers.c:1469:posix_janitor_task] 0-shared-posix: janitor cleaning out /opt/data/shared/.glusterfs/landfill
[2019-08-04 10:24:14.266439] D [MSGID: 0] [posix-metadata.c:118:posix_fetch_mdata_xattr] 0-shared-posix: No such attribute:trusted.glusterfs.mdata for file /opt/data/shared/.glusterfs/landfill gfid: null
[2019-08-04 10:24:14.372639] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:11) in:1, out:0, err:0
[2019-08-04 10:24:14.372670] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (11) is already connected
[2019-08-04 10:24:14.372676] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:14.372685] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:14.372699] T [rpcsvc.c:744:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 49090
[2019-08-04 10:24:14.372706] T [rpcsvc-auth.c:445:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS-v3
[2019-08-04 10:24:14.372713] T [rpcsvc.c:549:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x120987, Ver: 2, Program: 1298437, ProgVers: 400, Proc: 14) from rpc-transport (tcp.shared-server)
[2019-08-04 10:24:14.372724] T [auth-glusterfs.c:363:auth_glusterfs_v3_authenticate] 0-rpc-service: Auth Info: pid: 8258, uid: 694, gid: 692, owner: 0000000000000000, flags: 0
[2019-08-04 10:24:14.372729] T [rpcsvc.c:375:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 4.x v1 - STATFS for 10.7.1.209:49090
[2019-08-04 10:24:14.372744] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:11) socket_event_poll_in returned 0
[2019-08-04 10:24:14.372770] T [rpcsvc.c:375:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 4.x v1 - STATFS for 10.7.1.209:49090
[2019-08-04 10:24:14.372848] D [client_t.c:324:gf_client_ref] (-->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x34dd5) [0x7fb1c2a58dd5] -->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x115ed) [0x7fb1c2a355ed] -->/lib64/libglusterfs.so.0(gf_client_ref+0x6e) [0x7fb1d7b0fbde] ) 0-client_t: CTX_ID:ca89ac1a-1d4d-4aea-b264-fce7b1378aa4-GRAPH_ID:2-PID:22025-HOST:gfs-migration701-PC_NAME:shared-client-1-RECON_NO:-2: ref-count 2
[2019-08-04 10:24:14.372866] T [MSGID: 0] [server-rpc-fops_v2.c:2802:server4_statfs_resume] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-server to /opt/data/shared
[2019-08-04 10:24:14.372879] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from /opt/data/shared to shared-io-stats
[2019-08-04 10:24:14.372887] T [MSGID: 0] [io-stats.c:2906:io_stats_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-io-stats to shared-quota
[2019-08-04 10:24:14.372895] T [MSGID: 0] [quota.c:4557:quota_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-quota to shared-index
[2019-08-04 10:24:14.372902] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-index to shared-barrier
[2019-08-04 10:24:14.372908] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-barrier to shared-marker
[2019-08-04 10:24:14.372914] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-marker to shared-selinux
[2019-08-04 10:24:14.372921] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-selinux to shared-io-threads
[2019-08-04 10:24:14.372931] D [MSGID: 0] [io-threads.c:376:iot_schedule] 0-shared-io-threads: STATFS scheduled as fast priority fop
[2019-08-04 10:24:14.372970] T [MSGID: 0] [defaults.c:2325:default_statfs_resume] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-io-threads to shared-upcall
[2019-08-04 10:24:14.372991] T [MSGID: 0] [upcall.c:1232:up_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-upcall to shared-leases
[2019-08-04 10:24:14.373001] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-leases to shared-read-only
[2019-08-04 10:24:14.373013] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-read-only to shared-worm
[2019-08-04 10:24:14.373020] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-worm to shared-locks
[2019-08-04 10:24:14.373028] T [MSGID: 0] [posix.c:4388:pl_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-locks to shared-access-control
[2019-08-04 10:24:14.373035] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-access-control to shared-bitrot-stub
[2019-08-04 10:24:14.373041] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-bitrot-stub to shared-changelog
[2019-08-04 10:24:14.373047] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-changelog to shared-trash
[2019-08-04 10:24:14.373054] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-trash to shared-posix
[2019-08-04 10:24:14.373089] T [MSGID: 0] [posix-inode-fd-ops.c:2287:posix_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-posix returned 0
[2019-08-04 10:24:14.373097] T [MSGID: 0] [posix.c:4379:pl_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-locks returned 0
[2019-08-04 10:24:14.373104] T [MSGID: 0] [upcall.c:1211:up_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-upcall returned 0
[2019-08-04 10:24:14.373134] D [logging.c:2006:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
[2019-08-04 10:24:14.373129] T [MSGID: 0] [defaults.c:1642:default_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-io-threads returned 0
[2019-08-04 10:24:14.373132] T [MSGID: 0] [io-stats.c:2354:io_stats_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-io-stats returned 0
[2019-08-04 10:24:14.373161] T [rpcsvc.c:1533:rpcsvc_submit_generic] 0-rpc-service: Tx message: 108
[2019-08-04 10:24:14.373168] T [rpcsvc.c:1069:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 132, payload: 108, rpc hdr: 24
[2019-08-04 10:24:14.373192] T [rpcsvc.c:1585:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x1d89b, Program: GlusterFS 4.x v1, ProgVers: 400, Proc: 14) to rpc-transport (tcp.shared-server)
[2019-08-04 10:24:14.373231] D [client_t.c:433:gf_client_unref] (-->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x5afc3) [0x7fb1c2a7efc3] -->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0xadeb) [0x7fb1c2a2edeb] -->/lib64/libglusterfs.so.0(gf_client_unref+0x7b) [0x7fb1d7b0fd2b] ) 0-client_t: CTX_ID:ca89ac1a-1d4d-4aea-b264-fce7b1378aa4-GRAPH_ID:2-PID:22025-HOST:gfs-migration701-PC_NAME:shared-client-1-RECON_NO:-2: ref-count 1
[2019-08-04 10:24:18.703786] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:18.703846] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:18.703876] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:18.703887] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:18.703894] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:18.703910] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:18.703916] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:18.703934] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -12
[2019-08-04 10:24:18.703949] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:18.703954] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:18.703954] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:18.703968] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b80053f0 destroyed
[2019-08-04 10:24:18.703967] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (-1) is already connected
[2019-08-04 10:24:18.704080] E [socket.c:2317:__socket_proto_state_machine] (-->/lib64/libpthread.so.0(+0x7dd5) [0x7fb1d68eddd5] -->/lib64/libglusterfs.so.0(+0x8c286) [0x7fb1d7b13286] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0xc972) [0x7fb1cbe74972] ) 0-socket: invalid argument: this->private [Invalid argument]
[2019-08-04 10:24:18.704093] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:-1) socket_event_poll_in returned -1
[2019-08-04 10:24:18.704102] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:-1) 10.7.3.217 non-SSL (errno:-1:Unknown error -1)
[2019-08-04 10:24:18.704107] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:-1) (non-SSL)
[2019-08-04 10:24:18.704132] E [socket.c:1303:socket_event_poll_err] (-->/lib64/libglusterfs.so.0(+0x8c286) [0x7fb1d7b13286] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0xa48a) [0x7fb1cbe7248a] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0x81fc) [0x7fb1cbe701fc] ) 0-socket: invalid argument: this->private [Invalid argument]
[2019-08-04 10:24:18.704759] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:18.704776] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:18.704803] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:60044
[2019-08-04 10:24:18.704822] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:18.704827] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:18.704834] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:18.704838] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:18.704840] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:18.704847] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:18.704851] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:18.704858] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:18.704863] T [socket.c:2349:__socket_proto_state_machine] 0-tcp.shared-server: partial fragment header read
[2019-08-04 10:24:18.704870] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned 0
[2019-08-04 10:24:24.371032] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:11) in:1, out:0, err:0
[2019-08-04 10:24:24.371067] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (11) is already connected
[2019-08-04 10:24:24.371074] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:24.371084] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:24.371100] T [rpcsvc.c:744:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 49090
[2019-08-04 10:24:24.371109] T [rpcsvc-auth.c:445:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS-v3
[2019-08-04 10:24:24.371117] T [rpcsvc.c:549:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x120988, Ver: 2, Program: 1298437, ProgVers: 400, Proc: 14) from rpc-transport (tcp.shared-server)
[2019-08-04 10:24:24.371128] T [auth-glusterfs.c:363:auth_glusterfs_v3_authenticate] 0-rpc-service: Auth Info: pid: 8323, uid: 694, gid: 692, owner: 0000000000000000, flags: 0
[2019-08-04 10:24:24.371135] T [rpcsvc.c:375:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 4.x v1 - STATFS for 10.7.1.209:49090
[2019-08-04 10:24:24.371146] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:11) socket_event_poll_in returned 0
[2019-08-04 10:24:24.371159] T [rpcsvc.c:375:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 4.x v1 - STATFS for 10.7.1.209:49090
[2019-08-04 10:24:24.371229] D [client_t.c:324:gf_client_ref] (-->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x34dd5) [0x7fb1c2a58dd5] -->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x115ed) [0x7fb1c2a355ed] -->/lib64/libglusterfs.so.0(gf_client_ref+0x6e) [0x7fb1d7b0fbde] ) 0-client_t: CTX_ID:ca89ac1a-1d4d-4aea-b264-fce7b1378aa4-GRAPH_ID:2-PID:22025-HOST:gfs-migration701-PC_NAME:shared-client-1-RECON_NO:-2: ref-count 2
[2019-08-04 10:24:24.371253] D [logging.c:2006:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
The message "T [MSGID: 0] [server-rpc-fops_v2.c:2802:server4_statfs_resume] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-server to /opt/data/shared" repeated 2 times between [2019-08-04 10:23:34.373258] and [2019-08-04 10:24:24.371247]
[2019-08-04 10:24:24.371252] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from /opt/data/shared to shared-io-stats
[2019-08-04 10:24:24.371291] T [MSGID: 0] [io-stats.c:2906:io_stats_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-io-stats to shared-quota
[2019-08-04 10:24:24.371300] T [MSGID: 0] [quota.c:4557:quota_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-quota to shared-index
[2019-08-04 10:24:24.371309] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-index to shared-barrier
[2019-08-04 10:24:24.371316] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-barrier to shared-marker
[2019-08-04 10:24:24.371323] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-marker to shared-selinux
[2019-08-04 10:24:24.371331] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-selinux to shared-io-threads
[2019-08-04 10:24:24.371342] D [MSGID: 0] [io-threads.c:376:iot_schedule] 0-shared-io-threads: STATFS scheduled as fast priority fop
[2019-08-04 10:24:24.371419] T [MSGID: 0] [defaults.c:2325:default_statfs_resume] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-io-threads to shared-upcall
[2019-08-04 10:24:24.371442] T [MSGID: 0] [upcall.c:1232:up_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-upcall to shared-leases
[2019-08-04 10:24:24.371451] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-leases to shared-read-only
[2019-08-04 10:24:24.371458] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-read-only to shared-worm
[2019-08-04 10:24:24.371465] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-worm to shared-locks
[2019-08-04 10:24:24.371473] T [MSGID: 0] [posix.c:4388:pl_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-locks to shared-access-control
[2019-08-04 10:24:24.371480] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-access-control to shared-bitrot-stub
[2019-08-04 10:24:24.371486] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-bitrot-stub to shared-changelog
[2019-08-04 10:24:24.371492] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-changelog to shared-trash
[2019-08-04 10:24:24.371499] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, winding from shared-trash to shared-posix
[2019-08-04 10:24:24.371531] T [MSGID: 0] [posix-inode-fd-ops.c:2287:posix_statfs] 0-stack-trace: stack-address: 0x7fb18c000aa8, shared-posix returned 0
[2019-08-04 10:24:24.371539] T [MSGID: 0] [posix.c:4379:pl_statfs_cbk] 0-stack-trace: stack-address: 0x7fb18c000aa8, shared-locks returned 0
[2019-08-04 10:24:24.371545] T [MSGID: 0] [upcall.c:1211:up_statfs_cbk] 0-stack-trace: stack-address: 0x7fb18c000aa8, shared-upcall returned 0
[2019-08-04 10:24:24.371561] T [rpcsvc.c:1533:rpcsvc_submit_generic] 0-rpc-service: Tx message: 108
[2019-08-04 10:24:24.371568] T [rpcsvc.c:1069:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 132, payload: 108, rpc hdr: 24
[2019-08-04 10:24:24.371593] T [rpcsvc.c:1585:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x1d89c, Program: GlusterFS 4.x v1, ProgVers: 400, Proc: 14) to rpc-transport (tcp.shared-server)
[2019-08-04 10:24:24.371647] D [client_t.c:433:gf_client_unref] (-->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x5afc3) [0x7fb1c2a7efc3] -->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0xadeb) [0x7fb1c2a2edeb] -->/lib64/libglusterfs.so.0(gf_client_unref+0x7b) [0x7fb1d7b0fd2b] ) 0-client_t: CTX_ID:ca89ac1a-1d4d-4aea-b264-fce7b1378aa4-GRAPH_ID:2-PID:22025-HOST:gfs-migration701-PC_NAME:shared-client-1-RECON_NO:-2: ref-count 1
[2019-08-04 10:24:25.278101] D [logging.c:2006:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
The message "T [MSGID: 0] [io-stats.c:2354:io_stats_statfs_cbk] 0-stack-trace: stack-address: 0x7fb18c000aa8, shared-io-stats returned 0" repeated 2 times between [2019-08-04 10:23:34.373484] and [2019-08-04 10:24:24.371555]
[2019-08-04 10:24:25.278096] T [MSGID: 0] [posix-helpers.c:1469:posix_janitor_task] 0-shared-posix: janitor cleaning out /opt/data/shared/.glusterfs/landfill
[2019-08-04 10:24:25.278248] D [MSGID: 0] [posix-metadata.c:118:posix_fetch_mdata_xattr] 0-shared-posix: No such attribute:trusted.glusterfs.mdata for file /opt/data/shared/.glusterfs/landfill gfid: null
[2019-08-04 10:24:26.709885] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.709931] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.709938] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.709957] D [socket.c:692:__socket_rwv] 0-tcp.shared-server: EOF on socket 5 (errno:22:Invalid argument); returning ENODATA
[2019-08-04 10:24:26.709963] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.709972] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.709977] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.709992] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.711716] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.711739] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.711753] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34494
[2019-08-04 10:24:26.711772] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.711786] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.711796] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.711800] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.711810] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.711824] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.711830] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.712216] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295620 is serviced using standard calloc() (0x7fb1b8004f20) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.712243] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.712252] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (-788331683) received from 10.7.3.217:34494
[2019-08-04 10:24:26.712257] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.712267] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.712281] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.712287] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1b8004f20) allocated with standard calloc()
[2019-08-04 10:24:26.712319] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.712835] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.712858] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.712871] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34496
[2019-08-04 10:24:26.712890] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.712895] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.712904] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.712908] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.712915] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.712928] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.712934] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.713088] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295622 is serviced using standard calloc() (0x7fb1bc002160) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.713101] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.713109] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (134415197) received from 10.7.3.217:34496
[2019-08-04 10:24:26.713114] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.713123] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.713128] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.713133] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002160) allocated with standard calloc()
[2019-08-04 10:24:26.713157] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b80053f0 destroyed
[2019-08-04 10:24:26.713633] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.713649] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.713674] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34498
[2019-08-04 10:24:26.713689] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.713694] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.713702] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.713706] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.713711] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.713721] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.713730] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.713878] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295622 is serviced using standard calloc() (0x7fb1b8015f70) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.713890] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.713898] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (134415197) received from 10.7.3.217:34498
[2019-08-04 10:24:26.713902] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.713912] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.713916] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.713921] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1b8015f70) allocated with standard calloc()
[2019-08-04 10:24:26.713947] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.714466] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.714479] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.714489] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34500
[2019-08-04 10:24:26.714504] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.714509] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.714517] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.714522] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.714526] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.714535] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.714539] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.714694] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295622 is serviced using standard calloc() (0x7fb1bc002160) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.714709] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.714716] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (134415197) received from 10.7.3.217:34500
[2019-08-04 10:24:26.714720] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.714729] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.714733] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.714738] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002160) allocated with standard calloc()
[2019-08-04 10:24:26.714760] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b80053f0 destroyed
[2019-08-04 10:24:26.715392] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.715404] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.715412] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34502
[2019-08-04 10:24:26.715431] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.715436] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.715444] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.715448] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.715453] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.715464] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.715468] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.715624] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295622 is serviced using standard calloc() (0x7fb1b8015f70) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.715639] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.715647] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (134415197) received from 10.7.3.217:34502
[2019-08-04 10:24:26.715652] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.715660] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.715665] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.715670] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1b8015f70) allocated with standard calloc()
[2019-08-04 10:24:26.715694] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.716172] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.716186] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.716195] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34504
[2019-08-04 10:24:26.716216] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.716221] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.716228] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.716232] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.716234] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.716244] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.716248] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.716397] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369296132 is serviced using standard calloc() (0x7fb1bc002160) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.716407] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.716415] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (-1543306403) received from 10.7.3.217:34504
[2019-08-04 10:24:26.716419] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.716428] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.716437] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.716442] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002160) allocated with standard calloc()
[2019-08-04 10:24:26.716464] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b80053f0 destroyed
[2019-08-04 10:24:26.717115] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.717130] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.717140] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34506
[2019-08-04 10:24:26.717308] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.717314] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.717323] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.717327] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.717332] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.717336] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.717340] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.717480] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295620 is serviced using standard calloc() (0x7fb1bc002160) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.717490] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.717497] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (-100466339) received from 10.7.3.217:34506
[2019-08-04 10:24:26.717501] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.717509] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.717514] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.717518] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002160) allocated with standard calloc()
[2019-08-04 10:24:26.717540] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.718269] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.718286] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.718299] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34508
[2019-08-04 10:24:26.718319] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.718327] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.718339] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.718346] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.718348] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.718360] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.718369] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.718516] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295620 is serviced using standard calloc() (0x7fb1b8015f70) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.718527] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.718534] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (-100466339) received from 10.7.3.217:34508
[2019-08-04 10:24:26.718539] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.718548] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.718552] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.718557] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1b8015f70) allocated with standard calloc()
[2019-08-04 10:24:26.718582] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.719198] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.719215] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.719225] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34510
[2019-08-04 10:24:26.719241] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.719246] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.719254] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.719258] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.719266] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.719279] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.719286] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.719446] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295620 is serviced using standard calloc() (0x7fb1bc002160) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.719458] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.719466] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (-1107099299) received from 10.7.3.217:34510
[2019-08-04 10:24:26.719470] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.719479] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.719483] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.719488] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002160) allocated with standard calloc()
[2019-08-04 10:24:26.719511] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b80053f0 destroyed
[2019-08-04 10:24:26.719975] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.719990] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.720004] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34512
[2019-08-04 10:24:26.720019] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.720024] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.720031] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.720035] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.720040] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.720050] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.720054] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.720198] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295620 is serviced using standard calloc() (0x7fb1b8015f70) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.720209] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.720216] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (-2080177827) received from 10.7.3.217:34512
[2019-08-04 10:24:26.720221] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.720229] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.720234] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.720239] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1b8015f70) allocated with standard calloc()
[2019-08-04 10:24:26.720262] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.720613] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.720637] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.720647] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34514
[2019-08-04 10:24:26.720661] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.720666] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.720674] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.720678] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.720681] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.720693] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.720697] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.720848] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295364 is serviced using standard calloc() (0x7fb1bc002160) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.720859] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.720866] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (1812136029) received from 10.7.3.217:34514
[2019-08-04 10:24:26.720871] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.720883] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.720888] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.720892] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002160) allocated with standard calloc()
[2019-08-04 10:24:26.720914] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b80053f0 destroyed
[2019-08-04 10:24:26.721297] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.721308] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.721317] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34516
[2019-08-04 10:24:26.721344] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.721349] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.721358] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.721362] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.721371] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.721383] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.721388] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.721533] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295364 is serviced using standard calloc() (0x7fb1b8015f70) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.721544] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.721551] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (1241710685) received from 10.7.3.217:34516
[2019-08-04 10:24:26.721555] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.721564] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.721569] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.721574] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1b8015f70) allocated with standard calloc()

Comment 4 Marvin 2019-08-16 15:45:19 UTC
Part 2
[2019-08-04 10:24:26.721598] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.722058] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.722076] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.722086] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34518
[2019-08-04 10:24:26.722102] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.722107] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.722115] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.722119] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.722122] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.722134] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.722138] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.722281] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295364 is serviced using standard calloc() (0x7fb1bc002160) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.722290] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.722297] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (-1576861603) received from 10.7.3.217:34518
[2019-08-04 10:24:26.722302] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.722310] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.722314] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.722319] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002160) allocated with standard calloc()
[2019-08-04 10:24:26.722340] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b80053f0 destroyed
[2019-08-04 10:24:26.723181] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.723210] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.723230] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34520
[2019-08-04 10:24:26.723250] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.723257] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.723267] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.723272] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.723276] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.723289] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.723294] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.723440] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295364 is serviced using standard calloc() (0x7fb1b8015f70) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.723451] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.723460] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (-1576861603) received from 10.7.3.217:34520
[2019-08-04 10:24:26.723468] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.723480] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.723485] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.723490] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1b8015f70) allocated with standard calloc()
[2019-08-04 10:24:26.723517] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.724010] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.724027] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.724042] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34522
[2019-08-04 10:24:26.724056] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.724061] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.724073] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.724077] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.724079] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.724090] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.724097] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.724278] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295364 is serviced using standard calloc() (0x7fb1bc002160) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.724294] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.724304] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (1711472733) received from 10.7.3.217:34522
[2019-08-04 10:24:26.724310] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.724321] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.724326] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.724332] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002160) allocated with standard calloc()
[2019-08-04 10:24:26.724363] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b80053f0 destroyed
[2019-08-04 10:24:26.724764] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.724786] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.724802] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34524
[2019-08-04 10:24:26.724825] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.724831] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.724841] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.724846] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.724849] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.724858] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.724862] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.725011] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 369295364 is serviced using standard calloc() (0x7fb1b8015f70) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.725026] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.725037] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (1510146141) received from 10.7.3.217:34524
[2019-08-04 10:24:26.725045] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.725059] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.725064] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.725068] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1b8015f70) allocated with standard calloc()
[2019-08-04 10:24:26.725092] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:26.725438] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.725450] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.725459] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34526
[2019-08-04 10:24:26.725486] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.725492] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:26.725502] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:26.725506] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:26.725514] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:26.725524] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:26.725531] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.725557] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 3211524 is serviced using standard calloc() (0x7fb1bc002160) as it exceeds the maximum available buffer size
[2019-08-04 10:24:26.725570] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:26.725582] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (4103) received from 10.7.3.217:34526
[2019-08-04 10:24:26.725590] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -1
[2019-08-04 10:24:26.725600] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:26.725605] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:26.725611] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002160) allocated with standard calloc()
[2019-08-04 10:24:26.725655] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b80053f0 destroyed
[2019-08-04 10:24:26.726718] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:26.726736] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.726747] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34528
[2019-08-04 10:24:26.827220] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 19
[2019-08-04 10:24:26.827254] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 19, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.827269] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34536
[2019-08-04 10:24:26.927721] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 20
[2019-08-04 10:24:26.927768] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 20, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:26.927797] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34542
[2019-08-04 10:24:27.028127] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 21
[2019-08-04 10:24:27.028167] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 21, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:27.028190] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34548
[2019-08-04 10:24:27.128717] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 22
[2019-08-04 10:24:27.128787] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 22, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:27.128814] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34554
[2019-08-04 10:24:27.229151] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 23
[2019-08-04 10:24:27.229177] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 23, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:27.229192] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34568
[2019-08-04 10:24:27.329675] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 24
[2019-08-04 10:24:27.329713] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 24, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:27.329737] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34576
[2019-08-04 10:24:27.430084] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 25
[2019-08-04 10:24:27.430116] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 25, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:27.430132] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:34584
[2019-08-04 10:24:27.530284] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:27.530310] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:5) socket is not connected, completing connection
[2019-08-04 10:24:27.530326] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_complete_connection() returned 1
[2019-08-04 10:24:27.530332] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:5) returning to wait on socket
[2019-08-04 10:24:27.530348] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:27.530366] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:27.530373] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.530392] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -12
[2019-08-04 10:24:27.530405] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:5) in:1, out:0, err:0
[2019-08-04 10:24:27.530408] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:5) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:27.530412] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (5) is already connected
[2019-08-04 10:24:27.530415] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:5) (non-SSL)
[2019-08-04 10:24:27.530427] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:5) socket_event_poll_in returned -12
[2019-08-04 10:24:27.530441] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08d9b0 destroyed
[2019-08-04 10:24:27.530457] T [socket.c:231:socket_dump_info] 0- (errno:-1:Unknown error -1): $$$ server: disconnecting from (af:2,sock:-1) 10.7.3.217 non-SSL (errno:-1:Unknown error -1)
[2019-08-04 10:24:27.530465] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:-1) (non-SSL)
[2019-08-04 10:24:27.530514] E [socket.c:1303:socket_event_poll_err] (-->/lib64/libglusterfs.so.0(+0x8c286) [0x7fb1d7b13286] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0xa48a) [0x7fb1cbe7248a] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0x81fc) [0x7fb1cbe701fc] ) 0-socket: invalid argument: this->private [Invalid argument]
[2019-08-04 10:24:27.580375] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:19) in:1, out:0, err:0
[2019-08-04 10:24:27.580398] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:19) socket is not connected, completing connection
[2019-08-04 10:24:27.580411] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:19) socket_complete_connection() returned 1
[2019-08-04 10:24:27.580417] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:19) returning to wait on socket
[2019-08-04 10:24:27.580425] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:19) in:1, out:0, err:0
[2019-08-04 10:24:27.580431] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (19) is already connected
[2019-08-04 10:24:27.580436] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.580447] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.580453] T [socket.c:2349:__socket_proto_state_machine] 0-tcp.shared-server: partial fragment header read
[2019-08-04 10:24:27.630659] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:20) in:1, out:0, err:0
[2019-08-04 10:24:27.630697] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:20) socket is not connected, completing connection
[2019-08-04 10:24:27.630725] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:20) socket_complete_connection() returned 1
[2019-08-04 10:24:27.630737] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:20) returning to wait on socket
[2019-08-04 10:24:27.630763] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:20) in:1, out:0, err:0
[2019-08-04 10:24:27.630768] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (20) is already connected
[2019-08-04 10:24:27.630773] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.630817] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 67174404 is serviced using standard calloc() (0x7fb1bc002340) as it exceeds the maximum available buffer size
[2019-08-04 10:24:27.630834] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.630842] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.630854] T [socket.c:2231:__socket_read_frag] 0-tcp.shared-server: partial read on non-blocking socket
[2019-08-04 10:24:27.630862] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:20) socket_event_poll_in returned 0
[2019-08-04 10:24:27.680809] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:21) in:1, out:0, err:0
[2019-08-04 10:24:27.680846] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:21) socket is not connected, completing connection
[2019-08-04 10:24:27.680874] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:21) socket_complete_connection() returned 1
[2019-08-04 10:24:27.680885] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:21) returning to wait on socket
[2019-08-04 10:24:27.680910] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:21) in:1, out:0, err:0
[2019-08-04 10:24:27.680920] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (21) is already connected
[2019-08-04 10:24:27.680931] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.680979] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 486539780 is serviced using standard calloc() (0x7fb1bc091530) as it exceeds the maximum available buffer size
[2019-08-04 10:24:27.681010] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.681019] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (1650549872) received from 10.7.3.217:34548
[2019-08-04 10:24:27.681024] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:21) socket_event_poll_in returned -1
[2019-08-04 10:24:27.681038] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:21) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:27.681044] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:21) (non-SSL)
[2019-08-04 10:24:27.681050] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc091530) allocated with standard calloc()
[2019-08-04 10:24:27.681087] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08f130 destroyed
[2019-08-04 10:24:27.730907] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:22) in:1, out:0, err:0
[2019-08-04 10:24:27.730937] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:22) socket is not connected, completing connection
[2019-08-04 10:24:27.730950] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:22) socket_complete_connection() returned 1
[2019-08-04 10:24:27.730955] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:22) returning to wait on socket
[2019-08-04 10:24:27.730961] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:22) in:1, out:0, err:0
[2019-08-04 10:24:27.730965] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (22) is already connected
[2019-08-04 10:24:27.730970] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.730984] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:22) socket_event_poll_in returned -12
[2019-08-04 10:24:27.730997] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:22) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:27.731002] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:22) (non-SSL)
[2019-08-04 10:24:27.731000] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:22) in:1, out:0, err:0
[2019-08-04 10:24:27.731013] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08f960 destroyed
[2019-08-04 10:24:27.731017] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (-1) is already connected
[2019-08-04 10:24:27.731077] E [socket.c:2317:__socket_proto_state_machine] (-->/lib64/libpthread.so.0(+0x7dd5) [0x7fb1d68eddd5] -->/lib64/libglusterfs.so.0(+0x8c286) [0x7fb1d7b13286] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0xc972) [0x7fb1cbe74972] ) 0-socket: invalid argument: this->private [Invalid argument]
[2019-08-04 10:24:27.731093] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:-1) socket_event_poll_in returned -1
[2019-08-04 10:24:27.731102] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:-1) 10.7.3.217 non-SSL (errno:-1:Unknown error -1)
[2019-08-04 10:24:27.731108] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:-1) (non-SSL)
[2019-08-04 10:24:27.731138] E [socket.c:1303:socket_event_poll_err] (-->/lib64/libglusterfs.so.0(+0x8c286) [0x7fb1d7b13286] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0xa48a) [0x7fb1cbe7248a] -->/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0x81fc) [0x7fb1cbe701fc] ) 0-socket: invalid argument: this->private [Invalid argument]
[2019-08-04 10:24:27.781095] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:23) in:1, out:0, err:0
[2019-08-04 10:24:27.781133] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:23) socket is not connected, completing connection
[2019-08-04 10:24:27.781171] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:23) socket_complete_connection() returned 1
[2019-08-04 10:24:27.781183] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:23) returning to wait on socket
[2019-08-04 10:24:27.781189] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:23) in:1, out:0, err:0
[2019-08-04 10:24:27.781203] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (23) is already connected
[2019-08-04 10:24:27.781208] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.781240] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 944261959 is serviced using standard calloc() (0x7fb1bc0329b0) as it exceeds the maximum available buffer size
[2019-08-04 10:24:27.781253] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.781261] E [socket.c:2252:__socket_read_frag] 0-rpc: wrong MSG-TYPE (1299275112) received from 10.7.3.217:34568
[2019-08-04 10:24:27.781265] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:23) socket_event_poll_in returned -1
[2019-08-04 10:24:27.781275] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:23) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:27.781279] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:23) (non-SSL)
[2019-08-04 10:24:27.781284] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc0329b0) allocated with standard calloc()
[2019-08-04 10:24:27.781317] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc090190 destroyed
[2019-08-04 10:24:27.831241] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:24) in:1, out:0, err:0
[2019-08-04 10:24:27.831259] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:24) socket is not connected, completing connection
[2019-08-04 10:24:27.831271] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:24) socket_complete_connection() returned 1
[2019-08-04 10:24:27.831275] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:24) returning to wait on socket
[2019-08-04 10:24:27.831281] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:24) in:1, out:0, err:0
[2019-08-04 10:24:27.831285] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (24) is already connected
[2019-08-04 10:24:27.831290] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.831309] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.831323] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.831328] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.831333] T [socket.c:1651:__socket_read_request] 0-tcp.shared-server: partial read on non-blocking socket
[2019-08-04 10:24:27.831338] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:24) socket_event_poll_in returned 0
[2019-08-04 10:24:27.881538] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:25) in:1, out:0, err:0
[2019-08-04 10:24:27.881557] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:25) socket is not connected, completing connection
[2019-08-04 10:24:27.881576] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:25) socket_complete_connection() returned 1
[2019-08-04 10:24:27.881581] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:25) returning to wait on socket
[2019-08-04 10:24:27.881587] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:25) in:1, out:0, err:0
[2019-08-04 10:24:27.881591] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (25) is already connected
[2019-08-04 10:24:27.881596] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.881647] D [MSGID: 0] [iobuf.c:568:iobuf_get2] 0-iobuf: request for iobuf of size 989855748 is serviced using standard calloc() (0x7fb1bc0915a0) as it exceeds the maximum available buffer size
[2019-08-04 10:24:27.881662] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.881669] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.881677] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.881681] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:27.881686] T [socket.c:1419:__socket_read_simple_msg] 0-tcp.shared-server: partial read on non-blocking socket.
[2019-08-04 10:24:27.881692] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:25) socket_event_poll_in returned 0
[2019-08-04 10:24:34.370870] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:11) in:1, out:0, err:0
[2019-08-04 10:24:34.370906] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (11) is already connected
[2019-08-04 10:24:34.370913] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:34.370923] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:34.370942] T [rpcsvc.c:744:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 49090
[2019-08-04 10:24:34.370956] T [rpcsvc-auth.c:445:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS-v3
[2019-08-04 10:24:34.370956] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:11) in:1, out:0, err:0
[2019-08-04 10:24:34.370971] T [rpcsvc.c:549:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x120989, Ver: 2, Program: 1298437, ProgVers: 400, Proc: 14) from rpc-transport (tcp.shared-server)
[2019-08-04 10:24:34.370984] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (11) is already connected
[2019-08-04 10:24:34.371003] T [auth-glusterfs.c:363:auth_glusterfs_v3_authenticate] 0-rpc-service: Auth Info: pid: 9855, uid: 694, gid: 692, owner: 0000000000000000, flags: 0
[2019-08-04 10:24:34.371008] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:34.371018] T [rpcsvc.c:375:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 4.x v1 - STATFS for 10.7.1.209:49090
[2019-08-04 10:24:34.371033] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:34.371053] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:11) socket_event_poll_in returned 0
[2019-08-04 10:24:34.371077] T [rpcsvc.c:744:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 49090
[2019-08-04 10:24:34.371089] T [rpcsvc-auth.c:445:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS-v3
[2019-08-04 10:24:34.371096] T [rpcsvc.c:375:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 4.x v1 - STATFS for 10.7.1.209:49090
[2019-08-04 10:24:34.371099] T [rpcsvc.c:549:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x120990, Ver: 2, Program: 123451501, ProgVers: 1, Proc: 2) from rpc-transport (tcp.shared-server)
[2019-08-04 10:24:34.371126] T [auth-glusterfs.c:363:auth_glusterfs_v3_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 00000000, flags: 0
[2019-08-04 10:24:34.371144] T [rpcsvc.c:375:rpcsvc_program_actor] 0-rpc-service: Actor found: GF-DUMP - PING for 10.7.1.209:49090
[2019-08-04 10:24:34.371151] T [rpcsvc.c:1533:rpcsvc_submit_generic] 0-rpc-service: Tx message: 12
[2019-08-04 10:24:34.371157] T [rpcsvc.c:1069:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 36, payload: 12, rpc hdr: 24
[2019-08-04 10:24:34.371173] D [client_t.c:324:gf_client_ref] (-->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x34dd5) [0x7fb1c2a58dd5] -->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x115ed) [0x7fb1c2a355ed] -->/lib64/libglusterfs.so.0(gf_client_ref+0x6e) [0x7fb1d7b0fbde] ) 0-client_t: CTX_ID:ca89ac1a-1d4d-4aea-b264-fce7b1378aa4-GRAPH_ID:2-PID:22025-HOST:gfs-migration701-PC_NAME:shared-client-1-RECON_NO:-2: ref-count 2
[2019-08-04 10:24:34.371179] T [rpcsvc.c:1585:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x1d89e, Program: GF-DUMP, ProgVers: 1, Proc: 2) to rpc-transport (tcp.shared-server)
[2019-08-04 10:24:34.371197] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:11) socket_event_poll_in returned 0
[2019-08-04 10:24:34.371195] T [MSGID: 0] [server-rpc-fops_v2.c:2802:server4_statfs_resume] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-server to /opt/data/shared
[2019-08-04 10:24:34.371210] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from /opt/data/shared to shared-io-stats
[2019-08-04 10:24:34.371220] T [MSGID: 0] [io-stats.c:2906:io_stats_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-io-stats to shared-quota
[2019-08-04 10:24:34.371229] T [MSGID: 0] [quota.c:4557:quota_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-quota to shared-index
[2019-08-04 10:24:34.371237] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-index to shared-barrier
[2019-08-04 10:24:34.371245] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-barrier to shared-marker
[2019-08-04 10:24:34.371253] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-marker to shared-selinux
[2019-08-04 10:24:34.371260] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-selinux to shared-io-threads
[2019-08-04 10:24:34.371272] D [MSGID: 0] [io-threads.c:376:iot_schedule] 0-shared-io-threads: STATFS scheduled as fast priority fop
[2019-08-04 10:24:34.371305] T [MSGID: 0] [defaults.c:2325:default_statfs_resume] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-io-threads to shared-upcall
[2019-08-04 10:24:34.371321] T [MSGID: 0] [upcall.c:1232:up_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-upcall to shared-leases
[2019-08-04 10:24:34.371329] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-leases to shared-read-only
[2019-08-04 10:24:34.371336] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-read-only to shared-worm
[2019-08-04 10:24:34.371344] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-worm to shared-locks
[2019-08-04 10:24:34.371352] T [MSGID: 0] [posix.c:4388:pl_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-locks to shared-access-control
[2019-08-04 10:24:34.371359] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-access-control to shared-bitrot-stub
[2019-08-04 10:24:34.371365] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-bitrot-stub to shared-changelog
[2019-08-04 10:24:34.371372] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-changelog to shared-trash
[2019-08-04 10:24:34.371383] T [MSGID: 0] [defaults.c:3158:default_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, winding from shared-trash to shared-posix
[2019-08-04 10:24:34.371423] T [MSGID: 0] [posix-inode-fd-ops.c:2287:posix_statfs] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-posix returned 0
[2019-08-04 10:24:34.371436] T [MSGID: 0] [posix.c:4379:pl_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-locks returned 0
[2019-08-04 10:24:34.371460] D [logging.c:2006:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
[2019-08-04 10:24:34.371447] T [MSGID: 0] [upcall.c:1211:up_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-upcall returned 0
[2019-08-04 10:24:34.371458] T [MSGID: 0] [defaults.c:1642:default_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-io-threads returned 0
[2019-08-04 10:24:34.371494] T [rpcsvc.c:1533:rpcsvc_submit_generic] 0-rpc-service: Tx message: 108
[2019-08-04 10:24:34.371503] T [rpcsvc.c:1069:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 132, payload: 108, rpc hdr: 24
[2019-08-04 10:24:34.371529] T [rpcsvc.c:1585:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x1d89d, Program: GlusterFS 4.x v1, ProgVers: 400, Proc: 14) to rpc-transport (tcp.shared-server)
[2019-08-04 10:24:34.371577] D [client_t.c:433:gf_client_unref] (-->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0x5afc3) [0x7fb1c2a7efc3] -->/usr/lib64/glusterfs/6.1/xlator/protocol/server.so(+0xadeb) [0x7fb1c2a2edeb] -->/lib64/libglusterfs.so.0(gf_client_unref+0x7b) [0x7fb1d7b0fd2b] ) 0-client_t: CTX_ID:ca89ac1a-1d4d-4aea-b264-fce7b1378aa4-GRAPH_ID:2-PID:22025-HOST:gfs-migration701-PC_NAME:shared-client-1-RECON_NO:-2: ref-count 1
[2019-08-04 10:24:35.943492] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:19) in:1, out:0, err:0
[2019-08-04 10:24:35.943549] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (19) is already connected
[2019-08-04 10:24:35.943562] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:35.943590] D [socket.c:692:__socket_rwv] 0-tcp.shared-server: EOF on socket 19 (errno:11:Resource temporarily unavailable); returning ENODATA
[2019-08-04 10:24:35.943601] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:19) socket_event_poll_in returned -1
[2019-08-04 10:24:35.943615] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:19) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:35.943640] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:19) (non-SSL)
[2019-08-04 10:24:35.943655] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08e0d0 destroyed
[2019-08-04 10:24:35.943716] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 5
[2019-08-04 10:24:35.943730] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 5, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:35.943746] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:36410
[2019-08-04 10:24:35.943755] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:20) in:1, out:0, err:0
[2019-08-04 10:24:35.943771] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (20) is already connected
[2019-08-04 10:24:35.943777] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:35.943789] D [socket.c:692:__socket_rwv] 0-tcp.shared-server: EOF on socket 20 (errno:22:Invalid argument); returning ENODATA
[2019-08-04 10:24:35.943794] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:20) socket_event_poll_in returned -1
[2019-08-04 10:24:35.943812] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:20) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:35.943817] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:20) (non-SSL)
[2019-08-04 10:24:35.943828] D [logging.c:2006:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
[2019-08-04 10:24:34.371487] T [MSGID: 0] [io-stats.c:2354:io_stats_statfs_cbk] 0-stack-trace: stack-address: 0x7fb188000aa8, shared-io-stats returned 0
[2019-08-04 10:24:35.943824] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc002340) allocated with standard calloc()
[2019-08-04 10:24:35.943879] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc08e900 destroyed
[2019-08-04 10:24:35.943953] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 19
[2019-08-04 10:24:35.943965] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 19, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:35.943978] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:36412
[2019-08-04 10:24:35.944146] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 20
[2019-08-04 10:24:35.944157] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 20, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:35.944166] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:36414
[2019-08-04 10:24:35.944326] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 21
[2019-08-04 10:24:35.944336] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 21, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:35.944345] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:36416
[2019-08-04 10:24:35.944512] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:24) in:1, out:0, err:0
[2019-08-04 10:24:35.944517] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (24) is already connected
[2019-08-04 10:24:35.944522] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:35.944532] D [socket.c:692:__socket_rwv] 0-tcp.shared-server: EOF on socket 24 (errno:61:No data available); returning ENODATA
[2019-08-04 10:24:35.944537] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:24) socket_event_poll_in returned -1
[2019-08-04 10:24:35.944533] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 22
[2019-08-04 10:24:35.944544] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:24) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:35.944561] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:24) (non-SSL)
[2019-08-04 10:24:35.944571] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc0909c0 destroyed
[2019-08-04 10:24:35.944559] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 22, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:35.944591] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:36418
[2019-08-04 10:24:35.944846] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:25) in:1, out:0, err:0
[2019-08-04 10:24:35.944858] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (25) is already connected
[2019-08-04 10:24:35.944864] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:35.944872] D [socket.c:692:__socket_rwv] 0-tcp.shared-server: EOF on socket 25 (errno:61:No data available); returning ENODATA
[2019-08-04 10:24:35.944886] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 23
[2019-08-04 10:24:35.944894] W [socket.c:1410:__socket_read_simple_msg] 0-tcp.shared-server: reading from socket failed. Error (No data available), peer (10.7.3.217:34584)
[2019-08-04 10:24:35.944911] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 23, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:35.944913] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:25) socket_event_poll_in returned -1
[2019-08-04 10:24:35.944927] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:36420
[2019-08-04 10:24:35.944930] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:25) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:35.944936] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:25) (non-SSL)
[2019-08-04 10:24:35.944940] D [MSGID: 0] [iobuf.c:683:__iobuf_put] 0-iobuf: freeing the iobuf (0x7fb1bc0915a0) allocated with standard calloc()
[2019-08-04 10:24:35.944971] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1bc0866e0 destroyed
[2019-08-04 10:24:35.945018] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 24
[2019-08-04 10:24:35.945029] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 24, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:35.945040] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:36422
[2019-08-04 10:24:35.945202] T [socket.c:961:__socket_nodelay] 0-shared-server: NODELAY enabled for socket 25
[2019-08-04 10:24:35.945212] T [socket.c:1050:__socket_keepalive] 0-shared-server: Keep-alive enabled for socket: 25, (idle: 20, interval: 2, max-probes: 9, timeout: 42)
[2019-08-04 10:24:35.945220] T [socket.c:3086:socket_server_event_handler] 0-tcp.shared-server: XXX server:10.7.4.110:49156, client:10.7.3.217:36424
[2019-08-04 10:24:35.945259] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:25) in:1, out:0, err:0
[2019-08-04 10:24:35.945264] T [socket.c:2891:socket_event_handler] 0-tcp.shared-server: server (sock:25) socket is not connected, completing connection
[2019-08-04 10:24:35.945274] T [socket.c:2898:socket_event_handler] 0-tcp.shared-server: (sock:25) socket_complete_connection() returned 1
[2019-08-04 10:24:35.945279] T [socket.c:2902:socket_event_handler] 0-tcp.shared-server: (sock:25) returning to wait on socket
[2019-08-04 10:24:35.945284] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:25) in:1, out:0, err:0
[2019-08-04 10:24:35.945288] T [socket.c:2910:socket_event_handler] 0-tcp.shared-server: Server socket (25) is already connected
[2019-08-04 10:24:35.945292] T [socket.c:520:__socket_ssl_readv] 0-tcp.shared-server: ***** reading over non-SSL
[2019-08-04 10:24:35.945302] T [socket.c:2928:socket_event_handler] 0-tcp.shared-server: (sock:25) socket_event_poll_in returned -12
[2019-08-04 10:24:35.945311] T [socket.c:231:socket_dump_info] 0-tcp.shared-server: $$$ server: disconnecting from (af:2,sock:25) 10.7.3.217 non-SSL (errno:0:Success)
[2019-08-04 10:24:35.945315] D [socket.c:2946:socket_event_handler] 0-transport: EPOLLERR - disconnecting (sock:25) (non-SSL)
[2019-08-04 10:24:35.945322] T [socket.c:4583:fini] 0-tcp.shared-server: transport 0x7fb1b800d8a0 destroyed
[2019-08-04 10:24:35.945317] T [socket.c:2884:socket_event_handler] 0-tcp.shared-server: server (sock:25) in:1, out:0, err:0
[2019-08-04 10:24:35.945359] D [logging.c:1813:gf_log_flush_extra_msgs] 0-logging-infra: Log buffer size reduced. About to flush 5 extra log messages
[2019-08-04 10:24:24.371553] T [MSGID: 0] [defaults.c:1642:default_statfs_cbk] 0-stack-trace: stack-address: 0x7fb18c000aa8, shared-io-threads returned 0
[2019-08-04 10:24:35.945380] D [logging.c:1816:gf_log_flush_extra_msgs] 0-logging-infra: Just flushed 5 extra log messages
pending frames:
patchset: git://git.gluster.org/glusterfs.git
signal received: 11
time of crash:
2019-08-04 10:24:35
configuration details:
argp 1
backtrace 1
dlfcn 1
libpthread 1
llistxattr 1
setfsid 1
spinlock 1
epoll.h 1
xattr.h 1
st_atim.tv_nsec 1
package-string: glusterfs 6.1
/lib64/libglusterfs.so.0(+0x26db0)[0x7fb1d7aaddb0]
/lib64/libglusterfs.so.0(gf_print_trace+0x334)[0x7fb1d7ab87b4]
/lib64/libc.so.6(+0x36280)[0x7fb1d60ed280]
/usr/lib64/glusterfs/6.1/rpc-transport/socket.so(+0xa4cc)[0x7fb1cbe724cc]
/lib64/libglusterfs.so.0(+0x8c286)[0x7fb1d7b13286]
/lib64/libpthread.so.0(+0x7dd5)[0x7fb1d68eddd5]
/lib64/libc.so.6(clone+0x6d)[0x7fb1d61b4ead]
---------

Comment 5 M. Scherer 2019-08-19 09:33:26 UTC
Hi, in the future, could the logs be attached as files rather than used as comment ? This got blocked on mailman queue due to the size of the message :/

Comment 6 Calvin Dunigan 2019-08-31 00:14:50 UTC
We have encountered the same issue on gluster 6.4.  Does anyone know whether this affects older versions (e.g. 3.X)?

Comment 7 Calvin Dunigan 2019-09-16 22:41:10 UTC
A couple of observations that might be helpful to diagnose the problem.

Our security team has discovered that by using a full connection in nmap, while the "wrong MSG-TYPE" log errors are still generated, it does not trigger a crash of the brick.

A stop/start of the volume resolves the problem.  We do this from the node where the "crash" message appears in the log.

We share two volumes from the same cluster, only the larger one has ever crashed.  All other settings (options etc.) are the same.

Comment 8 Cybergavin 2019-10-04 04:06:29 UTC
Created attachment 1622480 [details]
GlusterFS brick crash during nexpose scan

Comment 9 Cybergavin 2019-10-04 04:18:54 UTC
We encountered the a gluster brick crash during a security scan using Rapid 7 Nexpose. We're on GlusterFS 6.5 and I've attached the log to my previous comment. The Rapid 7 scanner uses nmap and by default, I believe that a TCP SYN scan is performed. I will check with our Security folks and run a controlled test using both TCP SYN and TCP Connect (which I think Calvin referred to) scans and let you know the results.

Comment 10 Xavi Hernandez 2020-01-27 10:25:21 UTC
This is already fixed in v6.7 and v7.1.

*** This bug has been marked as a duplicate of bug 1749625 ***


Note You need to log in before you can comment on or make changes to this bug.