[Samba] Samba freezes

Antoine Huchet antoine at huchet.me
Sun Jun 25 16:11:05 UTC 2017


Hello,

I have Samba 4.5.8-Debian running on Debian Stretch.
I use Samba to load games over my local network from my Debian machine
to my Playstation 2 (using OpenPS2Loader:
https://github.com/Jay-Jay-OPL/OPL-Daily-Builds).

>From time to time, the game freezes, then after 5 minutes it comes back
(sometimes it doesn't, depends on the game).

Here is what I believe to be a relevant chunk of the logs:
> [2017/06/25 16:33:39.646102,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBreadX (pid 23003) conn 0x557ede2f1420
> [2017/06/25 16:33:39.646149,  3] ../source3/lib/util.c:1183(fcntl_getlock)
>   fcntl_getlock: fd 35 is returned info 2 pid 0
> [2017/06/25 16:33:39.646193,  3]
> ../source3/smbd/reply.c:4178(send_file_readX)
>   send_file_readX fnum 62440 max=2048 nread=2048
> [2017/06/25 16:33:39.649153,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 34186 of length 63 (0 toread)
> [2017/06/25 16:33:39.649209,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBreadX (pid 23003) conn 0x557ede2f1420
> [2017/06/25 16:33:39.649253,  3] ../source3/lib/util.c:1183(fcntl_getlock)
>   fcntl_getlock: fd 35 is returned info 2 pid 0
> [2017/06/25 16:33:39.649295,  3]
> ../source3/smbd/reply.c:4178(send_file_readX)
>   send_file_readX fnum 62440 max=2048 nread=2048
> [2017/06/25 16:33:39.657037,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 34187 of length 63 (0 toread)
> [2017/06/25 16:33:39.657093,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBreadX (pid 23003) conn 0x557ede2f1420
> [2017/06/25 16:33:39.657136,  3] ../source3/lib/util.c:1183(fcntl_getlock)
>   fcntl_getlock: fd 35 is returned info 2 pid 0
> [2017/06/25 16:33:39.657178,  3]
> ../source3/smbd/reply.c:4178(send_file_readX)
>   send_file_readX fnum 62440 max=2048 nread=2048
> [2017/06/25 16:34:22.747143,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1605 of length 42 (0 toread)
> [2017/06/25 16:34:22.747320,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:34:22.747448,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:35:24.191410,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1606 of length 42 (0 toread)
> [2017/06/25 16:35:24.191581,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:35:24.191760,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:36:25.627108,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1607 of length 42 (0 toread)
> [2017/06/25 16:36:25.627279,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:36:25.627422,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:37:27.067033,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1608 of length 42 (0 toread)
> [2017/06/25 16:37:27.067210,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:37:27.067363,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:38:28.506980,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1609 of length 42 (0 toread)
> [2017/06/25 16:38:28.507158,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:38:28.507291,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:39:29.947124,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1610 of length 42 (0 toread)
> [2017/06/25 16:39:29.947289,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:39:29.947406,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:40:31.390985,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1611 of length 42 (0 toread)
> [2017/06/25 16:40:31.391161,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:40:31.391307,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:41:05.373860,  3]
> ../source3/param/loadparm.c:3739(lp_load_ex)
>   lp_load_ex: refreshing parameters
> [2017/06/25 16:41:05.374001,  3]
> ../source3/param/loadparm.c:542(init_globals)
>   Initialising global parameters
> [2017/06/25 16:41:05.374140,  3]
> ../source3/param/loadparm.c:2668(lp_do_section)
>   Processing section "[global]"
> [2017/06/25 16:41:05.374241,  2]
> ../source3/param/loadparm.c:2685(lp_do_section)
>   Processing section "[PS2SMB]"
> [2017/06/25 16:41:05.374350,  2]
> ../source3/param/loadparm.c:2685(lp_do_section)
>   Processing section "[Partage]"
> [2017/06/25 16:41:05.374451,  3]
> ../source3/param/loadparm.c:1585(lp_add_ipc)
>   adding IPC service
> [2017/06/25 16:41:05.374721,  2]
> ../source3/lib/interface.c:345(add_interface)
>   added interface eth0 ip=192.168.2.4 bcast=192.168.2.255
> netmask=255.255.255.0
> [2017/06/25 16:41:32.826872,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1612 of length 42 (0 toread)
> [2017/06/25 16:41:32.827041,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:41:32.827176,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:42:34.268428,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1613 of length 42 (0 toread)
> [2017/06/25 16:42:34.268613,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:42:34.268818,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:43:35.706909,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 1614 of length 42 (0 toread)
> [2017/06/25 16:43:35.707081,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBecho (pid 17169) conn 0x0
> [2017/06/25 16:43:35.707221,  3] ../source3/smbd/reply.c:5789(reply_echo)
>   echo 1 times
> [2017/06/25 16:44:08.606358,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 34188 of length 63 (0 toread)
> [2017/06/25 16:44:08.606517,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBreadX (pid 23003) conn 0x557ede2f1420
> [2017/06/25 16:44:08.606667,  3] ../source3/lib/util.c:1183(fcntl_getlock)
>   fcntl_getlock: fd 35 is returned info 2 pid 0
> [2017/06/25 16:44:08.606737,  3]
> ../source3/smbd/reply.c:4178(send_file_readX)
>   send_file_readX fnum 62440 max=4096 nread=4096
> [2017/06/25 16:44:08.609392,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 34189 of length 63 (0 toread)
> [2017/06/25 16:44:08.609459,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBreadX (pid 23003) conn 0x557ede2f1420
> [2017/06/25 16:44:08.609511,  3] ../source3/lib/util.c:1183(fcntl_getlock)
>   fcntl_getlock: fd 35 is returned info 2 pid 0
> [2017/06/25 16:44:08.609560,  3]
> ../source3/smbd/reply.c:4178(send_file_readX)
>   send_file_readX fnum 62440 max=4096 nread=4096
> [2017/06/25 16:44:08.616655,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 34190 of length 63 (0 toread)
> [2017/06/25 16:44:08.616740,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBreadX (pid 23003) conn 0x557ede2f1420
> [2017/06/25 16:44:08.616788,  3] ../source3/lib/util.c:1183(fcntl_getlock)
>   fcntl_getlock: fd 35 is returned info 2 pid 0
> [2017/06/25 16:44:08.616834,  3]
> ../source3/smbd/reply.c:4178(send_file_readX)
>   send_file_readX fnum 62440 max=4096 nread=4096
> [2017/06/25 16:44:08.619438,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 34191 of length 63 (0 toread)
> [2017/06/25 16:44:08.619492,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBreadX (pid 23003) conn 0x557ede2f1420
> [2017/06/25 16:44:08.619537,  3] ../source3/lib/util.c:1183(fcntl_getlock)
>   fcntl_getlock: fd 35 is returned info 2 pid 0
> [2017/06/25 16:44:08.619579,  3]
> ../source3/smbd/reply.c:4178(send_file_readX)
>   send_file_readX fnum 62440 max=2048 nread=2048
> [2017/06/25 16:44:08.628418,  3]
> ../source3/smbd/process.c:1957(process_smb)
>   Transaction 34192 of length 63 (0 toread)
> [2017/06/25 16:44:08.628475,  3]
> ../source3/smbd/process.c:1538(switch_message)
>   switch message SMBreadX (pid 23003) conn 0x557ede2f1420

And here is the syslog at the same time:

> Jun 25 16:39:01 serveur CRON[23116]: (root) CMD (  [ -x
> /usr/lib/php5/sessionclean ] && /usr/lib/php5/sessionclean)
> Jun 25 16:41:05 serveur dhclient[717]: DHCPREQUEST of 192.168.2.4 on
> eth0 to 192.168.2.1 port 67
> Jun 25 16:41:05 serveur dhclient[717]: DHCPACK of 192.168.2.4 from
> 192.168.2.1
> Jun 25 16:41:05 serveur systemd[1]: Reloading Samba SMB Daemon.
> Jun 25 16:41:05 serveur systemd[1]: Reloaded Samba SMB Daemon.
> Jun 25 16:41:05 serveur dhclient[717]: bound to 192.168.2.4 -- renewal
> in 2912 seconds.

>From what I see, there is the usual stuff on top of the logs, then it
start echoing someting, then reloads and then it works again...

Any idea what might be causing that?

Thanks!

Best,
Antoine


More information about the samba mailing list