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:
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.
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()
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] ---------
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 :/
We have encountered the same issue on gluster 6.4. Does anyone know whether this affects older versions (e.g. 3.X)?
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.
Created attachment 1622480 [details] GlusterFS brick crash during nexpose scan
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.
This is already fixed in v6.7 and v7.1. *** This bug has been marked as a duplicate of bug 1749625 ***