From: unruh on
On 2010-01-16, lrhorer <lrhorer(a)satx.rr.com> wrote:
> lrhorer wrote:
>
>> No, I am insistent on tackling the more important issues
>> before moving
>> on to less important ones. Working out ppp issues, if any, is
>> trivial. No matter how well or poorly ppp is working, however, the
>> modem will
>> never dial out if the computer can't issue commands to it. Some of
>> these failure modes are encountered long before the router gets to the
>> point of starting to dial out. I need to resolve those sorts of
>> issues
>> before I try to dig in to problems with ppp. I also have not yet had
>> any time at all to work on any of the issues, no matter how large or
>> how small.
>>
>>>> It's not a "router". It's a router, specifically a Linux
>>>> router. It's
>>>> running Debian "Lenny" under kernel 2.6.26-2-686. The version of
>>>> pppd is 2.4.4 Rel 10.1, and of course it is from the Debian Stable
>>>> repository.
>>>
>>> Thanks. Please enable logging for pppd.
>>
>> It's already enabled. Next time I get a failure in a dialing
>> session,
>> I'll let you know what it says. It will probably be several days,
>> unless I get lucky, so to speak.
>
> OK, I was doing some testing and I had one of the lockups when I was
> sitting at the console. This was not one of the 12 hour lockups, as
> you can see from the logs. Here are the log outputs:
>
> Cricket:~# grep "Jan 16 00:" /var/log/messages
> Jan 16 00:19:37 Cricket rsyslogd: [origin software="rsyslogd"
> swVersion="3.18.6" x-pid="2245" x-info="http://www.rsyslog.com"]
> restart
> Jan 16 00:41:23 Cricket kernel: [ 1692.388023] usb 1-1: reset full speed
> USB device using uhci_hcd and address 3
> Jan 16 00:41:23 Cricket kernel: [ 1692.948014] usb 1-1: reset full speed
> USB device using uhci_hcd and address 3
> Jan 16 00:41:24 Cricket kernel: [ 1693.508017] usb 1-1: reset full speed
> USB device using uhci_hcd and address 3
> Jan 16 00:41:24 Cricket kernel: [ 1694.028016] usb 1-1: reset full speed
> USB device using uhci_hcd and address 3
> Jan 16 00:41:25 Cricket pppd[2682]: Modem hangup
> Jan 16 00:41:25 Cricket pppd[2682]: Connect time 27.6 minutes.
> Jan 16 00:41:25 Cricket pppd[2682]: Sent 144558 bytes, received 188005
> bytes.
> Jan 16 00:41:25 Cricket pppd[2682]: Connection terminated.
> Jan 16 00:41:25 Cricket kernel: [ 1694.440107] sd 0:0:0:0: Device
> offlined - not ready after error recovery
> Jan 16 00:41:25 Cricket kernel: [ 1694.440319] usb 1-1: USB disconnect,
> address 3
> Jan 16 00:41:25 Cricket pppd[2682]: Exit.
> Jan 16 00:41:25 Cricket kernel: [ 1694.552196] usb 1-1: new full speed
> USB device using uhci_hcd and address 4
> Jan 16 00:41:25 Cricket kernel: [ 1695.116015] usb 1-1: new full speed
> USB device using uhci_hcd and address 5
> Jan 16 00:41:26 Cricket kernel: [ 1695.676005] usb 1-1: new full speed
> USB device using uhci_hcd and address 6
> Jan 16 00:41:26 Cricket kernel: [ 1696.196015] usb 1-1: new full speed
> USB device using uhci_hcd and address 7
> Jan 16 00:43:32 Cricket kernel: [ 1821.624006] usb 1-1: new full speed
> USB device using uhci_hcd and address 8
> Jan 16 00:43:32 Cricket kernel: [ 1822.188016] usb 1-1: new full speed
> USB device using uhci_hcd and address 9
> Jan 16 00:43:33 Cricket kernel: [ 1822.748041] usb 1-1: new full speed
> USB device using uhci_hcd and address 10
> Jan 16 00:43:33 Cricket kernel: [ 1823.268022] usb 1-1: new full speed
> USB device using uhci_hcd and address 11
> Jan 16 00:48:25 Cricket kernel: [ 2115.128018] usb 1-1: new full speed
> USB device using uhci_hcd and address 12
> Jan 16 00:48:26 Cricket kernel: [ 2115.292074] usb 1-1: configuration #1
> chosen from 1 choice
> Jan 16 00:48:26 Cricket kernel: [ 2115.304881] scsi1 : SCSI emulation
> for USB Mass Storage devices
> Jan 16 00:48:26 Cricket kernel: [ 2115.305242] usb 1-1: New USB device
> found, idVendor=1f28, idProduct=0021
> Jan 16 00:48:26 Cricket kernel: [ 2115.305248] usb 1-1: New USB device
> strings: Mfr=1, Product=2, SerialNumber=3
> Jan 16 00:48:26 Cricket kernel: [ 2115.305253] usb 1-1: Product: USB
> Micro SD Storage
> Jan 16 00:48:26 Cricket kernel: [ 2115.305256] usb 1-1: Manufacturer:
> Cal-comp E&CC Limited
> Jan 16 00:48:26 Cricket kernel: [ 2115.305259] usb 1-1: SerialNumber:
> 214939913900
> Jan 16 00:48:31 Cricket kernel: [ 2120.308859] scsi 1:0:0:0:
> Direct-Access Cricket T-Flash Disk 2.31 PQ: 0 ANSI: 2
> Jan 16 00:48:31 Cricket kernel: [ 2120.308859] scsi 1:0:0:1: CD-ROM
> Cal-Comp CD INSTALLER 2.31 PQ: 0 ANSI: 0
> Jan 16 00:48:31 Cricket kernel: [ 2120.329118] sd 1:0:0:0: [sda]
> Attached SCSI removable disk
> Jan 16 00:48:31 Cricket kernel: [ 2120.556881] Driver 'sr' needs
> updating - please use bus_type methods
><snip>
>
>
> Cricket:~# grep "Jan 16 00:" /var/log/syslog
><snip>
> Jan 16 00:41:23 Cricket kernel: [ 1692.388023] usb 1-1: reset full speed
> USB device using uhci_hcd and address 3
> Jan 16 00:41:23 Cricket kernel: [ 1692.508017] usb 1-1: device
> descriptor read/64, error -71
> Jan 16 00:41:23 Cricket kernel: [ 1692.732031] usb 1-1: device
> descriptor read/64, error -71
> Jan 16 00:41:23 Cricket kernel: [ 1692.948014] usb 1-1: reset full speed
> USB device using uhci_hcd and address 3
> Jan 16 00:41:23 Cricket kernel: [ 1692.965250] cdc_acm: acm_ctrl_irq -
> usb_submit_urb failed with result -19
> Jan 16 00:41:23 Cricket kernel: [ 1693.068019] usb 1-1: device
> descriptor read/64, error -71
> Jan 16 00:41:24 Cricket kernel: [ 1693.292024] usb 1-1: device
> descriptor read/64, error -71
> Jan 16 00:41:24 Cricket kernel: [ 1693.508017] usb 1-1: reset full speed
> USB device using uhci_hcd and address 3
> Jan 16 00:41:24 Cricket kernel: [ 1693.916028] usb 1-1: device not
> accepting address 3, error -71
> Jan 16 00:41:24 Cricket kernel: [ 1694.028016] usb 1-1: reset full speed
> USB device using uhci_hcd and address 3
> Jan 16 00:41:25 Cricket pppd[2682]: Modem hangup
> Jan 16 00:41:25 Cricket pppd[2682]: Connect time 27.6 minutes.
> Jan 16 00:41:25 Cricket pppd[2682]: Sent 144558 bytes, received 188005
> bytes.
> Jan 16 00:41:25 Cricket pppd[2682]: Script /etc/ppp/ip-down started (pid
> 4457)
> Jan 16 00:41:25 Cricket pppd[2682]: Connection terminated.
> Jan 16 00:41:25 Cricket kernel: [ 1694.440021] usb 1-1: device not
> accepting address 3, error -71
> Jan 16 00:41:25 Cricket kernel: [ 1694.440107] sd 0:0:0:0: Device
> offlined - not ready after error recovery
> Jan 16 00:41:25 Cricket kernel: [ 1694.440319] usb 1-1: USB disconnect,
> address 3
> Jan 16 00:41:25 Cricket pppd[2682]: Waiting for 1 child processes...
> Jan 16 00:41:25 Cricket pppd[2682]: script /etc/ppp/ip-down, pid 4457
> Jan 16 00:41:25 Cricket pppd[2682]: Script /etc/ppp/ip-down finished
> (pid 4457), status = 0x0
> Jan 16 00:41:25 Cricket pppd[2682]: Exit.
> Jan 16 00:41:25 Cricket kernel: [ 1694.552196] usb 1-1: new full speed
> USB device using uhci_hcd and address 4
> Jan 16 00:41:25 Cricket kernel: [ 1694.676007] usb 1-1: device
> descriptor read/64, error -71
> Jan 16 00:41:25 Cricket kernel: [ 1694.900051] usb 1-1: device
> descriptor read/64, error -71
> Jan 16 00:41:25 Cricket kernel: [ 1695.116015] usb 1-1: new full speed
> USB device using uhci_hcd and address 5
> Jan 16 00:41:25 Cricket kernel: [ 1695.236042] usb 1-1: device
> descriptor read/64, error -71
> Jan 16 00:41:26 Cricket kernel: [ 1695.460007] usb 1-1: device
> descriptor read/64, error -71
> Jan 16 00:41:26 Cricket kernel: [ 1695.676005] usb 1-1: new full speed
> USB device using uhci_hcd and address 6
> Jan 16 00:41:26 Cricket kernel: [ 1696.084006] usb 1-1: device not
> accepting address 6, error -71
> Jan 16 00:41:26 Cricket kernel: [ 1696.196015] usb 1-1: new full speed
> USB device using uhci_hcd and address 7
> Jan 16 00:41:27 Cricket kernel: [ 1696.604019] usb 1-1: device not
> accepting address 7, error -71
> Jan 16 00:41:27 Cricket kernel: [ 1696.604049] hub 1-0:1.0: unable to
> enumerate USB device on port 1
><snip>
>
> Now will you believe me when I tell you pppd isn't issuing any errors
> and it is unlikely the networking layer is the culprit in most of these
> failures? Can we move on? I'll investigate possible networking issues
> later when I have these far more problematical and obvious problems
> ironed out.

You actually do not have debugging switched on for your pppd (option
debug to pppd), and thus the reason for the pppd disconnect is still
obscure. It looks like pppd is detecting a hangup, disconnects, and then your usb
bus is misbehaving. But there is no indication here why the hangup is
occuring.
You also seem to have a usb disk drive attached to
the usb bus, and it may be that there is some weird interaction between
the modem and the disk drive. It is a necessary drive? Can you remove it
for your tests?


From: Jerry Peters on
lrhorer <lrhorer(a)satx.rr.com> wrote:
>>> Yes, but that doesn't mean I require assistance
>>> troubleshooting it. I
>>> appreciate people wanting to be helpful, but I'm not new at dealing
>>> with electronics down to the component level. I wasn't new at it
>>> when the IBM PC was first introduced.
>>
>> Neither was I. I've found over may years of troubleshooting problems
>> that *most* people simply can't debug. I've worked on projects where
>> out of perhaps 20 or 30 people only 2 or 3 of us could debug
>> anything.
>
> Yeah, including a lot of people who are paid to be able to debug an
> troubleshoot. 'Paid a lot, sometimes.
>
>>>> Have you tried removing and re-inserting the cdc-acm
>>>> module? That *might* be enough to re-initialize the modem to a
>>>> usable state.
>>>
>>> I'll give it a shot when I get the chance.
>>>
>>>> There are also ways to control the power to a USB port via
>>>> sysfs I believe. This would allow you to fully reset the modem.
>>>
>>> Are you sure about that? I've looked, and I can't find any
>>> documentation to that effect. I'm working on writing a userspace
>>> binary to allow me to control the port, but if there is already a
>>> solution out there, I would be thrilled to use it. Of course, many
>>> USB ports do not have the capability in the first place, but if
>>> necessary I can use an external hub that does support power
>>> management.
>>>
>> No I'm not sure, hence the "I believe" part. It could also require an
>> ioctl or some other special operation. What happens if you remove
>> [eou]hci-hcd (the USB port driver)?
>
> Nothing at all, I think. I believe the device has to be commanded to
> down the port (and I believe it is port specific). I also have to
> qualify the statement with "I believe", because that just what the
> reading I have done and the people to whom I have spoken so far has
> suggested. One of the USB gurus tho whom I have spoken (Alan Stern at
> Harvard) has suggested the best way to approach the issue is to unbind
> the driver and then issue the command to shut down power on the port.
> That makes me think unbinding the driver isn't sufficient by itself.

linux/Documentation/usb/power-management.txt
Though I don't see any files except wakeup in the power
sub-directories when I look. Could be my Aspire 1 ports don't support
power management, or I didn't have the necessary options set when I
built the kernel.
I was going to suggest LKML, but if you're already corresponding with
Alan Stern that's superfulous. Did he suggest usbmon? That shows the
USB bus transactions which might help.
The problem could actually be a "feature" of the device, perhaps to
save power or eliminate the stupid dance to "safely remove hardware"
in Windows. The Windows program could "know" how to reactivate the
device.

>
>> Also there's additional debugging info that can be turned on for USB.
>> I think it's a kernel config option though.
>>
>>>> As for "interfacing the router's control scripts with the dialing
>>>> utility": chat.
>>>
>>> That seems to be the consensus.
>>
>> Yep, there's a good reason for that: flexibilty and control. I still
>> use dial-up when I visit my dad in Florida. I have a bash script which
>> builds the chat script (dependent on the modem & some options), then
>> invokes pppd with the connect option to actually do anything.
>>
>> Also 2.6.26 is an old kernel (late 2008), current stable is 2.6.32.3.
>
> Debian never packages the most recent versions of software, unless the
> release affects security or addresses a significant bug. It is an
> extremely conservative distribution, which is the main reason I use it.
> It definitely never has all the new bells and whistles, and it isn't
> for someone who wants to always have support for all the latest
> gadgets, but it is rock solid and provides new meaning for the
> term "stable". I use it on all my servers, and I am using it on this
> router in large measure because it is stable in the extreme. Most
> distros have maybe two versions, Stable and Unstable. Debian has
> Stable, Unstable, Testing, and Experimental, in order of decreasing
> reliability. What most distros call, "Stable", Debian calls "Testing".
> If you ask me, late 2008 isn't all that "old". A lot of bugs can go
> undetected after only a little more than 1 year in public release. If
> I need anything from one of the newer kernels, I can always download
> and compile it, but there's nothing from any of the newer kernels that
> is missing in 2.6.26 and that I need for this project. Indeed, I
> suspect I may never upgrade the kernel, or anything else, on this
> machine once it is permanently online. Its job is just to sit on the
> shelf, route packets, generate a firewall, provide DHCP support, and
> provide a VPN tunnel into my file server at my house.

Except that getting support for a year old kernel via LKML is likely
to be difficult. I'm surprised Alan Stern didn't suggest upgrading.

Jerry
From: Jerry Peters on
lrhorer <lrhorer(a)satx.rr.com> wrote:
----snip-----
>
>
> OK, I see, and I see now what you were saying. 'My mistake. When I
> read over that in the man page, I missed the /ppp/ and so I was
> thinking pppd was writing the file.
>
Usually you write /etc/resolv.conf from the /etc/ppp/ip-up script which
is passed all of the necessary information.

Jerry
From: lrhorer on
unruh wrote:

> On 2010-01-16, lrhorer <lrhorer(a)satx.rr.com> wrote:
>> lrhorer wrote:
>>
>>> No, I am insistent on tackling the more important issues
>>> before moving
>>> on to less important ones. Working out ppp issues, if any, is
>>> trivial. No matter how well or poorly ppp is working, however, the
>>> modem will
>>> never dial out if the computer can't issue commands to it. Some of
>>> these failure modes are encountered long before the router gets to
>>> the
>>> point of starting to dial out. I need to resolve those sorts of
>>> issues
>>> before I try to dig in to problems with ppp. I also have not yet
>>> had any time at all to work on any of the issues, no matter how
>>> large or how small.
>>>
>>>>> It's not a "router". It's a router, specifically a Linux
>>>>> router. It's
>>>>> running Debian "Lenny" under kernel 2.6.26-2-686. The version of
>>>>> pppd is 2.4.4 Rel 10.1, and of course it is from the Debian Stable
>>>>> repository.
>>>>
>>>> Thanks. Please enable logging for pppd.
>>>
>>> It's already enabled. Next time I get a failure in a
>>> dialing session,
>>> I'll let you know what it says. It will probably be several days,
>>> unless I get lucky, so to speak.
>>
>> OK, I was doing some testing and I had one of the lockups
>> when I was
>> sitting at the console. This was not one of the 12 hour lockups, as
>> you can see from the logs. Here are the log outputs:
>>
>> Cricket:~# grep "Jan 16 00:" /var/log/messages
>> Jan 16 00:19:37 Cricket rsyslogd: [origin software="rsyslogd"
>> swVersion="3.18.6" x-pid="2245" x-info="http://www.rsyslog.com"]
>> restart
>> Jan 16 00:41:23 Cricket kernel: [ 1692.388023] usb 1-1: reset full
>> speed USB device using uhci_hcd and address 3
>> Jan 16 00:41:23 Cricket kernel: [ 1692.948014] usb 1-1: reset full
>> speed USB device using uhci_hcd and address 3
>> Jan 16 00:41:24 Cricket kernel: [ 1693.508017] usb 1-1: reset full
>> speed USB device using uhci_hcd and address 3
>> Jan 16 00:41:24 Cricket kernel: [ 1694.028016] usb 1-1: reset full
>> speed USB device using uhci_hcd and address 3
>> Jan 16 00:41:25 Cricket pppd[2682]: Modem hangup
>> Jan 16 00:41:25 Cricket pppd[2682]: Connect time 27.6 minutes.
>> Jan 16 00:41:25 Cricket pppd[2682]: Sent 144558 bytes, received
>> 188005 bytes.
>> Jan 16 00:41:25 Cricket pppd[2682]: Connection terminated.
>> Jan 16 00:41:25 Cricket kernel: [ 1694.440107] sd 0:0:0:0: Device
>> offlined - not ready after error recovery
>> Jan 16 00:41:25 Cricket kernel: [ 1694.440319] usb 1-1: USB
>> disconnect, address 3
>> Jan 16 00:41:25 Cricket pppd[2682]: Exit.
>> Jan 16 00:41:25 Cricket kernel: [ 1694.552196] usb 1-1: new full
>> speed USB device using uhci_hcd and address 4
>> Jan 16 00:41:25 Cricket kernel: [ 1695.116015] usb 1-1: new full
>> speed USB device using uhci_hcd and address 5
>> Jan 16 00:41:26 Cricket kernel: [ 1695.676005] usb 1-1: new full
>> speed USB device using uhci_hcd and address 6
>> Jan 16 00:41:26 Cricket kernel: [ 1696.196015] usb 1-1: new full
>> speed USB device using uhci_hcd and address 7
>> Jan 16 00:43:32 Cricket kernel: [ 1821.624006] usb 1-1: new full
>> speed USB device using uhci_hcd and address 8
>> Jan 16 00:43:32 Cricket kernel: [ 1822.188016] usb 1-1: new full
>> speed USB device using uhci_hcd and address 9
>> Jan 16 00:43:33 Cricket kernel: [ 1822.748041] usb 1-1: new full
>> speed USB device using uhci_hcd and address 10
>> Jan 16 00:43:33 Cricket kernel: [ 1823.268022] usb 1-1: new full
>> speed USB device using uhci_hcd and address 11
>> Jan 16 00:48:25 Cricket kernel: [ 2115.128018] usb 1-1: new full
>> speed USB device using uhci_hcd and address 12
>> Jan 16 00:48:26 Cricket kernel: [ 2115.292074] usb 1-1: configuration
>> #1 chosen from 1 choice
>> Jan 16 00:48:26 Cricket kernel: [ 2115.304881] scsi1 : SCSI emulation
>> for USB Mass Storage devices
>> Jan 16 00:48:26 Cricket kernel: [ 2115.305242] usb 1-1: New USB
>> device found, idVendor=1f28, idProduct=0021
>> Jan 16 00:48:26 Cricket kernel: [ 2115.305248] usb 1-1: New USB
>> device strings: Mfr=1, Product=2, SerialNumber=3
>> Jan 16 00:48:26 Cricket kernel: [ 2115.305253] usb 1-1: Product: USB
>> Micro SD Storage
>> Jan 16 00:48:26 Cricket kernel: [ 2115.305256] usb 1-1: Manufacturer:
>> Cal-comp E&CC Limited
>> Jan 16 00:48:26 Cricket kernel: [ 2115.305259] usb 1-1: SerialNumber:
>> 214939913900
>> Jan 16 00:48:31 Cricket kernel: [ 2120.308859] scsi 1:0:0:0:
>> Direct-Access Cricket T-Flash Disk 2.31 PQ: 0 ANSI: 2
>> Jan 16 00:48:31 Cricket kernel: [ 2120.308859] scsi 1:0:0:1: CD-ROM
>> Cal-Comp CD INSTALLER 2.31 PQ: 0 ANSI: 0
>> Jan 16 00:48:31 Cricket kernel: [ 2120.329118] sd 1:0:0:0: [sda]
>> Attached SCSI removable disk
>> Jan 16 00:48:31 Cricket kernel: [ 2120.556881] Driver 'sr' needs
>> updating - please use bus_type methods
>><snip>
>>
>>
>> Cricket:~# grep "Jan 16 00:" /var/log/syslog
>><snip>
>> Jan 16 00:41:23 Cricket kernel: [ 1692.388023] usb 1-1: reset full
>> speed USB device using uhci_hcd and address 3
>> Jan 16 00:41:23 Cricket kernel: [ 1692.508017] usb 1-1: device
>> descriptor read/64, error -71
>> Jan 16 00:41:23 Cricket kernel: [ 1692.732031] usb 1-1: device
>> descriptor read/64, error -71
>> Jan 16 00:41:23 Cricket kernel: [ 1692.948014] usb 1-1: reset full
>> speed USB device using uhci_hcd and address 3
>> Jan 16 00:41:23 Cricket kernel: [ 1692.965250] cdc_acm: acm_ctrl_irq
>> - usb_submit_urb failed with result -19
>> Jan 16 00:41:23 Cricket kernel: [ 1693.068019] usb 1-1: device
>> descriptor read/64, error -71
>> Jan 16 00:41:24 Cricket kernel: [ 1693.292024] usb 1-1: device
>> descriptor read/64, error -71
>> Jan 16 00:41:24 Cricket kernel: [ 1693.508017] usb 1-1: reset full
>> speed USB device using uhci_hcd and address 3
>> Jan 16 00:41:24 Cricket kernel: [ 1693.916028] usb 1-1: device not
>> accepting address 3, error -71
>> Jan 16 00:41:24 Cricket kernel: [ 1694.028016] usb 1-1: reset full
>> speed USB device using uhci_hcd and address 3
>> Jan 16 00:41:25 Cricket pppd[2682]: Modem hangup
>> Jan 16 00:41:25 Cricket pppd[2682]: Connect time 27.6 minutes.
>> Jan 16 00:41:25 Cricket pppd[2682]: Sent 144558 bytes, received
>> 188005 bytes.
>> Jan 16 00:41:25 Cricket pppd[2682]: Script /etc/ppp/ip-down started
>> (pid 4457)
>> Jan 16 00:41:25 Cricket pppd[2682]: Connection terminated.
>> Jan 16 00:41:25 Cricket kernel: [ 1694.440021] usb 1-1: device not
>> accepting address 3, error -71
>> Jan 16 00:41:25 Cricket kernel: [ 1694.440107] sd 0:0:0:0: Device
>> offlined - not ready after error recovery
>> Jan 16 00:41:25 Cricket kernel: [ 1694.440319] usb 1-1: USB
>> disconnect, address 3
>> Jan 16 00:41:25 Cricket pppd[2682]: Waiting for 1 child processes...
>> Jan 16 00:41:25 Cricket pppd[2682]: script /etc/ppp/ip-down, pid
>> 4457 Jan 16 00:41:25 Cricket pppd[2682]: Script /etc/ppp/ip-down
>> finished (pid 4457), status = 0x0
>> Jan 16 00:41:25 Cricket pppd[2682]: Exit.
>> Jan 16 00:41:25 Cricket kernel: [ 1694.552196] usb 1-1: new full
>> speed USB device using uhci_hcd and address 4
>> Jan 16 00:41:25 Cricket kernel: [ 1694.676007] usb 1-1: device
>> descriptor read/64, error -71
>> Jan 16 00:41:25 Cricket kernel: [ 1694.900051] usb 1-1: device
>> descriptor read/64, error -71
>> Jan 16 00:41:25 Cricket kernel: [ 1695.116015] usb 1-1: new full
>> speed USB device using uhci_hcd and address 5
>> Jan 16 00:41:25 Cricket kernel: [ 1695.236042] usb 1-1: device
>> descriptor read/64, error -71
>> Jan 16 00:41:26 Cricket kernel: [ 1695.460007] usb 1-1: device
>> descriptor read/64, error -71
>> Jan 16 00:41:26 Cricket kernel: [ 1695.676005] usb 1-1: new full
>> speed USB device using uhci_hcd and address 6
>> Jan 16 00:41:26 Cricket kernel: [ 1696.084006] usb 1-1: device not
>> accepting address 6, error -71
>> Jan 16 00:41:26 Cricket kernel: [ 1696.196015] usb 1-1: new full
>> speed USB device using uhci_hcd and address 7
>> Jan 16 00:41:27 Cricket kernel: [ 1696.604019] usb 1-1: device not
>> accepting address 7, error -71
>> Jan 16 00:41:27 Cricket kernel: [ 1696.604049] hub 1-0:1.0: unable to
>> enumerate USB device on port 1
>><snip>
>>
>> Now will you believe me when I tell you pppd isn't issuing
>> any errors
>> and it is unlikely the networking layer is the culprit in most of
>> these
>> failures? Can we move on? I'll investigate possible networking
>> issues later when I have these far more problematical and obvious
>> problems ironed out.
>
> You actually do not have debugging switched on for your pppd (option
> debug to pppd)

Yes, I do. The debug directive is in the options file.

> , and thus the reason for the pppd disconnect is still
> obscure. It looks like pppd is detecting a hangup, disconnects, and
> then your usb bus is misbehaving.

No, look at the log, again. The USB reset occurs a full two seconds
before the pppd disconnect. The reset is at 41:23. The pppd hang-up
isn't until 41:25.

> But there is no indication here why
> the hangup is occuring.
> You also seem to have a usb disk drive attached to
> the usb bus, and it may be that there is some weird interaction
> between the modem and the disk drive. It is a necessary drive?

That's the modem. As I said before, it has an internal storage target
which is established when the modem is initialized. When the modem is
switched into modem mode, the drive target disappears and the modem
target becomes visible.
> Can you
> remove it for your tests?

No. It's built-in to the modem. It's also required for the
mode-switch.
From: unruh on
On 2010-01-16, lrhorer <lrhorer(a)satx.rr.com> wrote:
> unruh wrote:
>
>> On 2010-01-16, lrhorer <lrhorer(a)satx.rr.com> wrote:
>>> lrhorer wrote:
>>> Jan 16 00:41:25 Cricket kernel: [ 1694.900051] usb 1-1: device



>>
>> You actually do not have debugging switched on for your pppd (option
>> debug to pppd)
>
> Yes, I do. The debug directive is in the options file.

Good. But what you display is NOT the pppd debug logs.

Did you put the line
daemon.*;local2.* /var/log/daemonlog
(or whereever you want to put it) into /etc/syslog.conf, and restart
syslog.conf
killall -1 syslogd
?
Have you looked into /var/log/deamonlog ( or whereever you want to put
it) during that disconnect.

The log outputs you are giving are not from the pppd detailed logging.


>
>> , and thus the reason for the pppd disconnect is still
>> obscure. It looks like pppd is detecting a hangup, disconnects, and
>> then your usb bus is misbehaving.
>
> No, look at the log, again. The USB reset occurs a full two seconds
> before the pppd disconnect. The reset is at 41:23. The pppd hang-up
> isn't until 41:25.

It may be. As I say I would like to see the detailed pppd debug logs
before I say what is going on.

>
>> But there is no indication here why
>> the hangup is occuring.
>> You also seem to have a usb disk drive attached to
>> the usb bus, and it may be that there is some weird interaction
>> between the modem and the disk drive. It is a necessary drive?
>
> That's the modem. As I said before, it has an internal storage target
> which is established when the modem is initialized. When the modem is
> switched into modem mode, the drive target disappears and the modem
> target becomes visible.

Ah, OK, so somehow the modem is resetting itself off the bus.
Again, I really really would advise getting a new, different modem.

>> Can you
>> remove it for your tests?
>
> No. It's built-in to the modem. It's also required for the
> mode-switch.

OK, so that fact that it is appearing here indicates that the modem has
reset itself.
Is it possible that for some reason the power to the modem is being
interrupted causing the disconnect-- eg flakey usb port?