Bug#511996: sl-modem-daemon: slmodemd doesn't work, process unkillable (fwd) (fwd)
Maurizio Avogadro wrote: Il 13/02/2009 00:14, Corey Hickey ha scritto: There aren't any flags on the open() system call; O_CREAT would be needed. The data file is actually created on the first write: modem/modem_datafile.c:110, function datafile_save_info() -- int fd; fd = open(file_name,O_CREAT|O_WRONLY,(S_IRUSR|S_IWUSR)); if(fd 0) return -errno; [...] -- During my quick tests the file has been created the second time I tried to start slmodemd; notice that the first datafile_load_info() happens before dropping privileges: if the file is created at that time it will be root:root. You're right, and I see that behavior now too. The file is created on the first run, before slmodemd exits. On the second run, the file is available, and slmodemd can open it for reading. I just did a quick grep of the source, before, and I didn't realize the file was created elsewhere from where it was read; sorry for wasting your time on that. Anyway, to answer your original question about the file's permissions: # ls -l /var/lib/slmodem/data.modem\:1 -rw--- 1 Slmodemd Slmodemd 24 Feb 14 20:14 /var/lib/slmodem/data.modem:1 In case it's of any use, I'm attaching a couple log files: slmodemd_2.6.26-1-686.log slmodemd_2.6.26-1-686_no-drop-privs.log I couldn't get your logs, please send them again. Argh, I forgot them. They're attached this time. Anyway, I made some tests and - since now - I couldn't reproduce this issue, at least with current 2.6.26-1 Lenny kernel. I think at this point it would be useful for me to summarize my current understanding of what's going on in this bug report, since it has sort of split into three different issues. 1. slmodemd hangs and isn't killable under kernels configured with a particular realtime scheduling configuration. This was the original reason for my bug report, and I have tracked it down to a kernel bug (or at least some nasty behavior, if the kernel developers decide it's not a bug). I sent a report and a test program to the LKML several hours ago: http://lkml.org/lkml/2009/2/14/272 2. slmodemd creates /var/lib/slmodem/data.modem:1 before exit; that was just me being confused, so I think this issue can be dropped. 3. On a non-realtime kernel, such as the standard Debian 2.6.26-1-686 kernel, slmodemd doesn't work for me with 10_drop_priveliges.diff applied, with this error: 164.501196 err: modem:1: modem start = -1: cannot start device. On that last issue, I dug around with gdb a bit, starting with the function in which that error message is printed. modem.c:1140, function modem_start() modem_comp_init() fails modem_comp.c:795, function modem_comp_init() comp_init() fails modem_comp.c:730, function comp_init() COMP_ALLOC(dict_size*sizeof(*d)); fails That last part turns into: malloc(2048 * 8); I don't know why the malloc() fails. I went to the same line in my slmodemd binary that doesn't have 10_drop_privileges.diff, and that malloc() succeeded, with the same arguments. Going back to the regular privilege-dropping binary, I used gdb to run some malloc() tests immediately before and immediately after the setuid() call. The results showed that malloc() could only allocate a small amount of memory after the setuid(). I still don't know why that is. I cut modem_main.c down to just the privilege-dropping code and made it a standalone program, and that didn't have any trouble allocating lots of memory after the setuid(). My Slmodemd user doesn't have any memory allocation limits, as far as I can tell (ulimit -a). I'll do some more investigation, but that will have to wait a day or two. If you have any tips meanwhile, please let me know. Thanks, Corey 161.740201 SmartLink Soft Modem: version 2.9.11 Feb 11 2009 17:18:39 161.740285 modem:1: startup modem... 161.740448 modem:1: update termios... symbolic link `/dev/ttySL0' - `/dev/pts/0' created. modem `modem:1' created. TTY is `/dev/pts/0' 161.741660 open file: /var/lib/slmodem/data.modem:1... 161.742914 main: rt applyed: SCHED_FIFO, pri 99 161.743206 main: dropped privileges to 114.105 Use `/dev/ttySL0' as modem device, Ctrl+C for termination. 163.934191 main: termios changed. 163.934234 modem:1: update termios... 164.000320 main: termios changed. 164.000344 modem:1: update termios... 164.101065 modem:1: run cmd: AT 164.101090 modem:1: modem report result: 0 (OK) 164.200483 modem:1: run cmd: ATFC1D2V1S0=0 164.200515 modem:1: modem report result: 0 (OK) 164.301602 modem:1: run cmd: ATS7=60S30=0M1%C1\N3K3N1X1 164.301641 main: alsa_ioctl: cmd 8, arg 0... 164.301680 modem:1: modem report result: 0 (OK) 164.401317 modem:1: run cmd: AT+MS=34 164.401364 modem:1: modem report result: 0 (OK) 164.500957 modem:1: run cmd: ATDT1-760-933-2451 164.500994 modem:1: modem dial: T1-760-933-2451... 164.501004 modem:1:
Bug#511996: sl-modem-daemon: slmodemd doesn't work, process unkillable (fwd) (fwd)
Corey Hickey wrote: I don't know why the malloc() fails. I went to the same line in my slmodemd binary that doesn't have 10_drop_privileges.diff, and that malloc() succeeded, with the same arguments. Going back to the regular privilege-dropping binary, I used gdb to run some malloc() tests immediately before and immediately after the setuid() call. The results showed that malloc() could only allocate a small amount of memory after the setuid(). Ok, here's the problem. modem_main.c:976 function modem_main() -- if (need_realtime) { struct sched_param prm; if(mlockall(MCL_CURRENT|MCL_FUTURE)) { ERR(mlockall: %s\n,strerror(errno)); } -- That chunk of code runs when slmodemd starts up; the modem_start() code I mentioned in my last email runs when the modem is dialed. So, the mlockall(MCL_FUTURE) is allowing only a very limited allocation of memory after the setuid(). Here's a gdb log of me breaking execution right after the above code and then running setuid() and malloc(); the first malloc(16384) works, but the next ones fail. -- # gdb modem/slmodemd GNU gdb 6.8-debian Copyright (C) 2008 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type show copying and show warranty for details. This GDB was configured as i486-linux-gnu... (gdb) b modem_main.c:981 Breakpoint 1 at 0x804b748: file modem_main.c, line 981. (gdb) r -a --debug Starting program: /usr/local/src/sl-modem/sl-modem-2.9.11~20080817/modem/slmodemd -a --debug [Thread debugging using libthread_db enabled] [New Thread 0xb7cf26b0 (LWP 9688)] SmartLink Soft Modem: version 2.9.11 Feb 15 2009 15:24:03 425.285129 SmartLink Soft Modem: version 2.9.11 Feb 15 2009 15:24:03 425.285334 modem:1: startup modem... 425.285634 modem:1: update termios... symbolic link `/dev/ttySL0' - `/dev/pts/4' created. modem `modem:1' created. TTY is `/dev/pts/4' 425.301313 open file: /var/lib/slmodem/data.modem:1... [Switching to Thread 0xb7cf26b0 (LWP 9688)] Breakpoint 1, modem_main (dev_name=0x810b0b7 modem:1) at modem_main.c:981 981prm.sched_priority = sched_get_priority_max(SCHED_FIFO); (gdb) print setuid(105) $1 = 0 (gdb) print malloc(16384) $2 = 163347000 (gdb) $3 = 0 (gdb) $4 = 0 (gdb) $5 = 0 (gdb) -- Removing the MCL_FUTURE flag makes slmodemd work for me, as far as I can tell. Remember that I don't have a phone line to test here. It gets past the modem_start() code, at least, and behaves just like my binary that has the privilege-dropping patch removed. I don't know if that's an acceptable solution; locking all allocated memory into RAM seems useful. Then again, I wouldn't really expect a currently-running slmodemd process to get swapped out unless memory constraints are extreme. I don't know the original rationale. -Corey -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#511996: sl-modem-daemon: slmodemd doesn't work, process unkillable (fwd) (fwd)
Il 13/02/2009 00:14, Corey Hickey ha scritto: [...] It appears that slmodemd isn't creating /var/lib/slmodem/data.modem:1 even though it should have permissions to create files in the directory (isn't it still running as root at that point, anyway?). Actually, now that I check the source, that makes sense: modem/modem_datafile.c:70, function datafile_load_info() -- int fd; DBG(open file: %s...\n,file_name); fd = open(file_name, 0, 0); if(fd 0) { DBG(cannot open '%s': %s\n, file_name,strerror(errno)); return -errno; } -- There aren't any flags on the open() system call; O_CREAT would be needed. The data file is actually created on the first write: modem/modem_datafile.c:110, function datafile_save_info() -- int fd; fd = open(file_name,O_CREAT|O_WRONLY,(S_IRUSR|S_IWUSR)); if(fd 0) return -errno; [...] -- During my quick tests the file has been created the second time I tried to start slmodemd; notice that the first datafile_load_info() happens before dropping privileges: if the file is created at that time it will be root:root. [...] Il 13/02/2009 01:11, Corey Hickey ha scritto: [...] In case it's of any use, I'm attaching a couple log files: slmodemd_2.6.26-1-686.log slmodemd_2.6.26-1-686_no-drop-privs.log I couldn't get your logs, please send them again. Anyway, I made some tests and - since now - I couldn't reproduce this issue, at least with current 2.6.26-1 Lenny kernel. Maurizio -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#511996: sl-modem-daemon: slmodemd doesn't work, process unkillable (fwd) (fwd)
Corey Hickey wrote: I just tried the Debian 2.6.26-1-686 kernel, and the slmodemd process was killable, but the modem didn't work: it kept responding NO CARRIER immediately after dialing. [cut] I'm going to try to figure out what it is in my particular kernel configuration that's causing slmodemd to be unkillable, but that's going to take a while. Hang in there... Ok, I have it narrowed down to CONFIG_RT_GROUP_SCHED. With this option disabled, slmodemd is killable. The unpatched version still doesn't work for me (NO CARRIER as described above), but I'll get back to that. I think it's a related but separate problem. As for CONFIG_RT_GROUP_SCHED: -- Group scheduling for SCHED_RR/FIFO This feature lets you explicitly allocate real CPU bandwidth to users or control groups (depending on the Basis for grouping tasks setting below. If enabled, it will also make it impossible to schedule realtime tasks for non-root users until you allocate realtime bandwidth for them. See Documentation/sched-rt-group.txt for more information. -- By default, the kernel doesn't allow non-root users to have an CPU time for running realtime tasks. slmodemd is setting itself to SCHED_FIFO, changing its user to Slmodemd, and then being denied any CPU time. The kernel isn't supposed to allow processes to set themselves to SCHED_FIFO if the user don't have any realtime CPU bandwidth. I can allocate bandwidth to the Slmodemd user and make slmodemd killable. Alternatively, I can just use slmodemd -n -a to avoid realtime scheduling, now that I know what the problem is. I'm sure this problem could be worked around somehow in the slmodemd code, but I think it would be nicer if the kernel behaved differently. I found a similar problem reported about a year ago, which appears to be fixed before the 2.6.26 kernel I tested. bug report: http://lkml.org/lkml/2008/1/31/490 test case: http://lkml.org/lkml/2008/2/5/535 ...however, the problem I'm having with slmodemd is subtly different. If I understand the bug reported above, it relates to a process that is either running setuid root or with an RLIMIT_RTPRIO value that allows it to set itself realtime. slmodemd, however, sets itself realtime while running as root, then changes to a regular user, hence bypassing the checks added in response to that bug report. I guess I'll try to bring this to the kernel developers' attention tomorrow. -Corey -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#511996: sl-modem-daemon: slmodemd doesn't work, process unkillable (fwd) (fwd)
- Forwarded message from Maurizio Avogadro mav...@gmail.com - sorry for my late but I'm very busy... after the first glance: 1. I noticed that some previous version left a - ---Sr--r-T root root data.(slamr|modem:)[0-9] file in /var/lib/slmodem: maybe the slmodemd daemon is unable to access that file after dropping the privileges. This didn't happen in my case. Can that user simply try to delete that file and restart the daemon (it will be created anew as - -rw--- 1 Slmodemd Slmodemd data.(slamr|modem:)[0-9] if not after the first slmodemd run, after the second)? 2. What are the permissions of /var/lib/slmodem? Maurizio -- أحمد المحمودي (Ahmed El-Mahmoudy) Digital design engineer GPG KeyID: 0x9DCA0B27 (@ subkeys.pgp.net) GPG Fingerprint: 087D 3767 8CAC 65B1 8F6C 156E D325 C3C8 9DCA 0B27 -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#511996: sl-modem-daemon: slmodemd doesn't work, process unkillable (fwd) (fwd)
أحمد المحمودي wrote: - Forwarded message from Maurizio Avogadro mav...@gmail.com - sorry for my late but I'm very busy... after the first glance: 1. I noticed that some previous version left a - ---Sr--r-T root root data.(slamr|modem:)[0-9] file in /var/lib/slmodem: maybe the slmodemd daemon is unable to access that file after dropping the privileges. This didn't happen in my case. Can that user simply try to delete that file and restart the daemon (it will be created anew as - -rw--- 1 Slmodemd Slmodemd data.(slamr|modem:)[0-9] if not after the first slmodemd run, after the second)? 2. What are the permissions of /var/lib/slmodem? /var/lib/slmodem didn't exist for me, apparently due to bug #421867. At the time I filed this bug, I was using version 2.9.11~20080817-1, and that bug was fixed in 2.9.11~20080817-2. I just upgraded to 2.9.11~20080817-3, and /var/lib/slmodem was created: $ ls -l /var/lib | grep slmodem drwxr-xr-x 2 Slmodemd adm48 2009-02-12 13:15:39 slmodem When I run slmodemd, no files get created in /var/lib/slmodem, though. The output looks like this: -- # slmodemd -a --debug SmartLink Soft Modem: version 2.9.11 Feb 11 2009 17:18:39 904.573094 SmartLink Soft Modem: version 2.9.11 Feb 11 2009 17:18:39 904.573174 modem:1: startup modem... 904.573351 modem:1: update termios... symbolic link `/dev/ttySL0' - `/dev/pts/2' created. modem `modem:1' created. TTY is `/dev/pts/2' 904.574521 open file: /var/lib/slmodem/data.modem:1... 904.574610 cannot open '/var/lib/slmodem/data.modem:1': No such file or directory 904.589214 main: rt applyed: SCHED_FIFO, pri 99 904.589650 main: dropped privileges to 114.105 Use `/dev/ttySL0' as modem device, Ctrl+C for termination. -- It appears that slmodemd isn't creating /var/lib/slmodem/data.modem:1 even though it should have permissions to create files in the directory (isn't it still running as root at that point, anyway?). Actually, now that I check the source, that makes sense: modem/modem_datafile.c:70, function datafile_load_info() -- int fd; DBG(open file: %s...\n,file_name); fd = open(file_name, 0, 0); if(fd 0) { DBG(cannot open '%s': %s\n, file_name,strerror(errno)); return -errno; } -- There aren't any flags on the open() system call; O_CREAT would be needed. Anyway, I went ahead and created the file with the permissions/ownership you listed above, and now the output looks like this: -- # slmodemd -a --debug SmartLink Soft Modem: version 2.9.11 Feb 11 2009 17:18:39 309.699510 SmartLink Soft Modem: version 2.9.11 Feb 11 2009 17:18:39 309.699590 modem:1: startup modem... 309.699755 modem:1: update termios... symbolic link `/dev/ttySL0' - `/dev/pts/1' created. modem `modem:1' created. TTY is `/dev/pts/1' 309.700894 open file: /var/lib/slmodem/data.modem:1... 309.763599 main: rt applyed: SCHED_FIFO, pri 99 309.764034 main: dropped privileges to 114.105 Use `/dev/ttySL0' as modem device, Ctrl+C for termination. -- I have some bad news, though. I had reported earlier that my problem went away when I upgraded my kernel to 2.6.28. It appears I was mistaken; I guess I had installed my modified Debian package and completely forgotten about it; so, when I tested slmodemd under 2.6.28, it simply wasn't dropping privileges because I had removed that functionality. So, please don't close this bug yet, since I spoke too soon. Thanks, Corey -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org
Bug#511996: sl-modem-daemon: slmodemd doesn't work, process unkillable (fwd) (fwd)
I just tried the Debian 2.6.26-1-686 kernel, and the slmodemd process was killable, but the modem didn't work: it kept responding NO CARRIER immediately after dialing. In case it's of any use, I'm attaching a couple log files: slmodemd_2.6.26-1-686.log slmodemd_2.6.26-1-686_no-drop-privs.log The first log shows slmodemd starting up, and then I run wvdial in another terminal; slmodemd has problems and responds NO CARRIER a couple times before I kill wvdial. The second log is the same, but the modem at least attempts to dial. I can't actually test dialing right now, because I don't have access to a phone line here. I'm pretty sure it would work, though, since it did before. I'm going to try to figure out what it is in my particular kernel configuration that's causing slmodemd to be unkillable, but that's going to take a while. Hang in there... -Corey -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of unsubscribe. Trouble? Contact listmas...@lists.debian.org