Re: [hylafax-users] problem "waiting for modem to came ready"

[Fabio Nigi <nigifabio@xxxxxx>]

Siri Vias Khalsa wrote:
> Fabio - 
> 
> Please send the log of one of the failed calls. From what I can see
> here, it looks like you are getting incoming calls that do not complete,
> every 3-4 minutes during one period there. The call lengths are all very
> similar, so I would guess that it is timing out, not getting the
> response it expected.
> 



this is the error message that i found until modem become waiting
hope is  it usefully

Feb 10 08:49:32.83: [ 4017]: <-- [9:AT+FTH=3\r]
Feb 10 08:49:32.86: [ 4017]: --> [7:CONNECT]
Feb 10 08:49:32.86: [ 4017]: <-- data [3]
Feb 10 08:49:32.86: [ 4017]: <-- data [2]
Feb 10 08:49:34.16: [ 4017]: --> [2:OK]
Feb 10 08:49:34.16: [ 4017]: <-- [11:AT+FRM=146\r]
Feb 10 08:49:34.61: [ 4017]: --> [7:CONNECT]
Feb 10 08:49:34.61: [ 4017]: RECV: begin page
Feb 10 08:50:09.91: [ 4017]: RECV: 2394 total lines, 0 bad lines, 0
consecutive bad lines
Feb 10 08:50:09.91: [ 4017]: RECV: end page
Feb 10 08:50:09.91: [ 4017]: --> [10:NO CARRIER]
Feb 10 08:50:09.91: [ 4017]: <-- [9:AT+FRH=3\r]
Feb 10 08:50:10.37: [ 4017]: --> [7:CONNECT]
Feb 10 08:50:11.26: [ 4017]: --> [2:OK]
Feb 10 08:50:11.26: [ 4017]: RECV recv EOP (no more pages or documents)
Feb 10 08:50:11.26: [ 4017]: DELAY 70 ms
Feb 10 08:50:11.33: [ 4017]: <-- [9:AT+FTH=3\r]
Feb 10 08:50:11.47: [ 4017]: --> [7:CONNECT]
Feb 10 08:50:11.47: [ 4017]: <-- data [3]
Feb 10 08:50:11.47: [ 4017]: <-- data [2]
Feb 10 08:50:12.77: [ 4017]: --> [2:OK]
Feb 10 08:50:12.77: [ 4017]: RECV send MCF (message confirmation)
Feb 10 08:50:12.77: [ 4017]: RECV FAX (000000290): from Fax, page 1 in
0:47, A4, 7.7 line/mm, 2-D MR, 14400 bit/s
Feb 10 08:50:12.77: [ 4017]: RECV FAX (000000290):
recvq/fax000000188.tif from Fax, route to <unspecified>, 1 pages in 0:50
Feb 10 08:50:12.77: [ 4017]: <-- [9:AT+FRH=3\r]
Feb 10 08:50:13.48: [ 4017]: --> [7:CONNECT]
Feb 10 08:50:14.53: [ 4017]: --> [2:OK]
Feb 10 08:50:14.53: [ 4017]: RECV recv DCN (disconnect)
Feb 10 08:50:14.53: [ 4017]: RECV FAX: bin/faxrcvd
"recvq/fax000000188.tif" "ttyS0" "000000290" ""
Feb 10 08:50:14.53: [ 4017]: RECV FAX: end
Feb 10 08:50:14.53: [ 4017]: SESSION END


02/09/09 09:54	RECV	000000286	ttyS0		""	fax	"7364726"	"050877040"
2220073	2	7:46	7:46	"T.30 T2 timeout, expected signal not
received"	""	""	""	""	"00 46 1F 23 01 01 01 01 01 00"
02/09/09 09:53	CALL	000000286	ttyS0		""	fax	"7364726"	""	0	0	8:00	8:00
"T.30 T2 timeout, expected signal not received"	""	""	""	""	""
02/09/09 11:57	RECV	000000287	ttyS0		""	fax	"7364726"	"050877040"
2220073	2	2:55	2:55	""	""	""	""	""	"00 46 1F 23 01 01 01 01 01 00"
02/09/09 11:57	CALL	000000287	ttyS0		""	fax	"7364726"	""	0	0	3:02
3:02	""	""	""	""	""	""
02/09/09 15:53	RECV	000000288	ttyS0		""	fax	"7364726"	""	2105384	1
0:54	0:54	""	""	""	""	""	"00 44 1E"
02/09/09 15:53	CALL	000000288	ttyS0		""	fax	"7364726"	""	0	0	1:01
1:01	""	""	""	""	""	""
02/09/09 17:03	RECV	000000289	ttyS0		""	fax	"7364726"	"055219397"
2220072	4	1:29	1:29	""	""	""	""	""	"00 44 1F 23 01 00"
02/09/09 17:03	CALL	000000289	ttyS0		""	fax	"7364726"	""	0	0	1:36
1:36	""	""	""	""	""	""
02/10/09 08:49	RECV	000000290	ttyS0		""	fax	"7364726"	"Fax"
2375721	1	0:50	0:50	""	""	""	""	""	"00 47 08"
02/10/09 08:49	CALL	000000290	ttyS0		""	fax	"7364726"	""	0	0	0:58
0:58	""	""	""	""	""	""
fanfaniserver:/var/spool/hylafax/log#


thanks


> On Mon, 2009-02-09 at 12:39 -0600, Fabio Nigi wrote:
>> hi all,
>> i have changed my modem, with one of the supported list on the site,
>> the problem persist, debian installation i follow the howto on hylafax
>> web site:
>>
>> 02/06/09 17:38	CALL	000000274	ttyS0		""	fax	"7364726"	""	0	0	0:28	0:28
>> "COMREC invalid response received"	""	""	""	""	""
>> 02/06/09 17:41	CALL	000000275	ttyS0		""	fax	"7364726"	""	0	0	0:48	0:48
>> "RSPREC error/got DCN (sender abort)"	""	""	""	""	""
>> 02/06/09 17:45	CALL	000000276	ttyS0		""	fax	"7364726"	""	0	0	0:47	0:47
>> "RSPREC error/got DCN (sender abort)"	""	""	""	""	""
>> 02/06/09 17:49	CALL	000000277	ttyS0		""	fax	"7364726"	""	0	0	0:48	0:48
>> "RSPREC error/got DCN (sender abort)"	""	""	""	""	""
>> 02/06/09 17:53	CALL	000000278	ttyS0		""	fax	"7364726"	""	0	0	0:47	0:47
>> "RSPREC error/got DCN (sender abort)"	""	""	""	""	""
>> 02/06/09 17:56	CALL	000000279	ttyS0		""	fax	"7364726"	""	0	0	0:52	0:52
>> "RSPREC error/got DCN (sender abort)"	""	""	""	""	""
>> 02/06/09 18:00	CALL	000000280	ttyS0		""	fax	"7364726"	""	0	0	0:47	0:47
>> "RSPREC error/got DCN (sender abort)"	""	""	""	""	""
>> 02/06/09 18:04	CALL	000000281	ttyS0		""	fax	"7364726"	""	0	0	0:47	0:47
>> "RSPREC error/got DCN (sender abort)"	""	""	""	""	""
>> 02/06/09 18:08	CALL	000000282	ttyS0		""	fax	"7364726"	""	0	0	0:47	0:47
>> "RSPREC error/got DCN (sender abort)"	""	""	""	""	""
>> 02/09/09 09:19	RECV	000000283	ttyS0		""	fax	"7364726"	"Fax"
>> 2375721	1	0:49	0:49	""	""	""	""	""	"00 47 08"
>> 02/09/09 09:19	CALL	000000283	ttyS0		""	fax	"7364726"	""	0	0	0:57
>> 0:57	""	""	""	""	""	""
>>
>> i found lot's of this error message on the log,
>>
>> after same received fax (can be 10 or 100)modem stop working, until i
>> restart hylafax, or reboot the server.
>>
>> faxstat said: "waiting for modem to came ready"
>>
>> a log of a received fax:
>>
>> Feb 09 17:04:27.71: [ 4031]: --> [10:NO CARRIER]
>> Feb 09 17:04:27.71: [ 4031]: <-- [9:AT+FRH=3\r]
>> Feb 09 17:04:28.10: [ 4031]: --> [7:CONNECT]
>> Feb 09 17:04:29.13: [ 4031]: --> [2:OK]
>> Feb 09 17:04:29.13: [ 4031]: RECV recv PPS (partial page signal)
>> Feb 09 17:04:29.13: [ 4031]: RECV recv MPS (more pages, same document)
>> Feb 09 17:04:29.13: [ 4031]: RECV received 119 frames of block 1 of page 3
>> Feb 09 17:04:29.15: [ 4031]: RECV: 29925 bytes of data, 1146 total lines
>> Feb 09 17:04:29.16: [ 4031]: DELAY 70 ms
>> Feb 09 17:04:29.23: [ 4031]: <-- [9:AT+FTH=3\r]
>> Feb 09 17:04:29.26: [ 4031]: --> [7:CONNECT]
>> Feb 09 17:04:29.26: [ 4031]: RECV send MCF (message confirmation)
>> Feb 09 17:04:29.26: [ 4031]: <-- data [3]
>> Feb 09 17:04:29.26: [ 4031]: <-- data [2]
>> Feb 09 17:04:29.27: [ 4031]: RECV FAX (000000289): from 055219397, page
>> 3 in 0:23, INF, 3.85 line/mm, 2-D MMR, 14400 bit/s
>> Feb 09 17:04:30.56: [ 4031]: --> [2:OK]
>> Feb 09 17:04:30.56: [ 4031]: <-- [11:AT+FRM=146\r]
>> Feb 09 17:04:31.54: [ 4031]: --> [7:CONNECT]
>> Feb 09 17:04:32.03: [ 4031]: RECV received frame number 0
>> Feb 09 17:04:32.24: [ 4031]: RECV received frame number 1
>> Feb 09 17:04:32.38: [ 4031]: RECV received frame number 2
>> Feb 09 17:04:32.52: [ 4031]: RECV received frame number 3
>> Feb 09 17:04:32.66: [ 4031]: RECV received frame number 4
>> Feb 09 17:04:32.80: [ 4031]: RECV received frame number 5
>> Feb 09 17:04:32.94: [ 4031]: RECV received frame number 6
>> Feb 09 17:04:33.08: [ 4031]: RECV received frame number 7
>> Feb 09 17:04:33.23: [ 4031]: RECV received frame number 8
>> Feb 09 17:04:33.37: [ 4031]: RECV received frame number 9
>> Feb 09 17:04:33.58: [ 4031]: RECV received frame number 10
>> Feb 09 17:04:33.72: [ 4031]: RECV received frame number 11
>> Feb 09 17:04:33.86: [ 4031]: RECV received frame number 12
>> Feb 09 17:04:34.00: [ 4031]: RECV received frame number 13
>> Feb 09 17:04:34.14: [ 4031]: RECV received frame number 14
>> Feb 09 17:04:34.28: [ 4031]: RECV received frame number 15
>> Feb 09 17:04:34.43: [ 4031]: RECV received frame number 16
>> Feb 09 17:04:34.57: [ 4031]: RECV received frame number 17
>> Feb 09 17:04:34.78: [ 4031]: RECV received frame number 18
>> Feb 09 17:04:34.92: [ 4031]: RECV received frame number 19
>> Feb 09 17:04:35.06: [ 4031]: RECV received frame number 20
>> Feb 09 17:04:35.20: [ 4031]: RECV received frame number 21
>> Feb 09 17:04:35.34: [ 4031]: RECV received frame number 22
>> Feb 09 17:04:35.48: [ 4031]: RECV received frame number 23
>> Feb 09 17:04:35.62: [ 4031]: RECV received frame number 24
>> Feb 09 17:04:35.83: [ 4031]: RECV received frame number 25
>> Feb 09 17:04:35.97: [ 4031]: RECV received frame number 26
>> Feb 09 17:04:36.12: [ 4031]: RECV received frame number 27
>> Feb 09 17:04:36.26: [ 4031]: RECV received frame number 28
>> Feb 09 17:04:36.40: [ 4031]: RECV received frame number 29
>> Feb 09 17:04:36.54: [ 4031]: RECV received frame number 30
>> Feb 09 17:04:36.68: [ 4031]: RECV received frame number 31
>> Feb 09 17:04:36.82: [ 4031]: RECV received frame number 32
>> Feb 09 17:04:37.04: [ 4031]: RECV received frame number 33
>> Feb 09 17:04:37.18: [ 4031]: RECV received frame number 34
>> Feb 09 17:04:37.32: [ 4031]: RECV received frame number 35
>> Feb 09 17:04:37.46: [ 4031]: RECV received frame number 36
>> Feb 09 17:04:37.60: [ 4031]: RECV received frame number 37
>> Feb 09 17:04:37.74: [ 4031]: RECV received frame number 38
>> Feb 09 17:04:37.88: [ 4031]: RECV received frame number 39
>> Feb 09 17:04:38.02: [ 4031]: RECV received frame number 40
>> Feb 09 17:04:38.23: [ 4031]: RECV received frame number 41
>> Feb 09 17:04:38.37: [ 4031]: RECV received frame number 42
>> Feb 09 17:04:38.51: [ 4031]: RECV received frame number 43
>> Feb 09 17:04:38.65: [ 4031]: RECV received frame number 44
>> Feb 09 17:04:38.79: [ 4031]: RECV received frame number 45
>> Feb 09 17:04:38.93: [ 4031]: RECV received frame number 46
>> Feb 09 17:04:39.07: [ 4031]: RECV received frame number 47
>> Feb 09 17:04:39.28: [ 4031]: RECV received frame number 48
>> Feb 09 17:04:39.42: [ 4031]: RECV received frame number 49
>> Feb 09 17:04:39.56: [ 4031]: RECV received frame number 50
>> Feb 09 17:04:39.70: [ 4031]: RECV received frame number 51
>> Feb 09 17:04:39.84: [ 4031]: RECV received frame number 52
>> Feb 09 17:04:39.98: [ 4031]: RECV received frame number 53
>> Feb 09 17:04:40.12: [ 4031]: RECV received frame number 54
>> Feb 09 17:04:40.34: [ 4031]: RECV received frame number 55
>> Feb 09 17:04:40.48: [ 4031]: RECV received frame number 56
>> Feb 09 17:04:40.62: [ 4031]: RECV received frame number 57
>> Feb 09 17:04:40.76: [ 4031]: RECV received frame number 58
>> Feb 09 17:04:40.90: [ 4031]: RECV received frame number 59
>> Feb 09 17:04:41.04: [ 4031]: RECV received frame number 60
>> Feb 09 17:04:41.18: [ 4031]: RECV received frame number 61
>> Feb 09 17:04:41.32: [ 4031]: RECV received frame number 62
>> Feb 09 17:04:41.53: [ 4031]: RECV received frame number 63
>> Feb 09 17:04:41.67: [ 4031]: RECV received frame number 64
>> Feb 09 17:04:41.81: [ 4031]: RECV received frame number 65
>> Feb 09 17:04:41.95: [ 4031]: RECV received frame number 66
>> Feb 09 17:04:42.09: [ 4031]: RECV received frame number 67
>> Feb 09 17:04:42.23: [ 4031]: RECV received frame number 68
>> Feb 09 17:04:42.37: [ 4031]: RECV received frame number 69
>> Feb 09 17:04:42.51: [ 4031]: RECV received frame number 70
>> Feb 09 17:04:42.72: [ 4031]: RECV received frame number 71
>> Feb 09 17:04:42.86: [ 4031]: RECV received frame number 72
>> Feb 09 17:04:43.00: [ 4031]: RECV received frame number 73
>> Feb 09 17:04:43.15: [ 4031]: RECV received frame number 74
>> Feb 09 17:04:43.28: [ 4031]: RECV received frame number 75
>> Feb 09 17:04:43.42: [ 4031]: RECV received frame number 76
>> Feb 09 17:04:43.57: [ 4031]: RECV received frame number 77
>> Feb 09 17:04:43.78: [ 4031]: RECV received frame number 78
>> Feb 09 17:04:43.92: [ 4031]: RECV received frame number 79
>> Feb 09 17:04:44.06: [ 4031]: RECV received frame number 80
>> Feb 09 17:04:44.06: [ 4031]: RECV received RCP frame
>> Feb 09 17:04:44.20: [ 4031]: --> [10:NO CARRIER]
>> Feb 09 17:04:44.20: [ 4031]: <-- [9:AT+FRH=3\r]
>> Feb 09 17:04:44.60: [ 4031]: --> [7:CONNECT]
>> Feb 09 17:04:45.63: [ 4031]: --> [2:OK]
>> Feb 09 17:04:45.63: [ 4031]: RECV recv PPS (partial page signal)
>> Feb 09 17:04:45.63: [ 4031]: RECV recv EOP (no more pages or documents)
>> Feb 09 17:04:45.63: [ 4031]: RECV received 81 frames of block 1 of page 4
>> Feb 09 17:04:45.65: [ 4031]: RECV: 20495 bytes of data, 1165 total lines
>> Feb 09 17:04:45.65: [ 4031]: DELAY 70 ms
>> Feb 09 17:04:45.72: [ 4031]: <-- [9:AT+FTH=3\r]
>> Feb 09 17:04:45.76: [ 4031]: --> [7:CONNECT]
>> Feb 09 17:04:45.76: [ 4031]: <-- data [3]
>> Feb 09 17:04:45.76: [ 4031]: <-- data [2]
>> Feb 09 17:04:47.05: [ 4031]: --> [2:OK]
>> Feb 09 17:04:47.05: [ 4031]: RECV send MCF (message confirmation)
>> Feb 09 17:04:47.05: [ 4031]: RECV FAX (000000289): from 055219397, page
>> 4 in 0:16, INF, 3.85 line/mm, 2-D MMR, 14400 bit/s
>> Feb 09 17:04:47.05: [ 4031]: RECV FAX (000000289):
>> recvq/fax000000187.tif from 055219397, route to <unspecified>, 4 pages
>> in 1:29
>> Feb 09 17:04:47.05: [ 4031]: <-- [9:AT+FRH=3\r]
>> Feb 09 17:04:47.48: [ 4031]: --> [7:CONNECT]
>> Feb 09 17:04:48.37: [ 4031]: --> [2:OK]
>> Feb 09 17:04:48.37: [ 4031]: RECV recv DCN (disconnect)
>> Feb 09 17:04:48.37: [ 4031]: RECV FAX: bin/faxrcvd
>> "recvq/fax000000187.tif" "ttyS0" "000000289" ""
>> Feb 09 17:04:48.37: [ 4031]: RECV FAX: end
>> Feb 09 17:04:48.37: [ 4031]: SESSION END
>>
>>
>> no strange conf, only pdf mail.
>>
>> the server only receive fax i don't understand where is the problem
>>
>> sameone can help me??
>>
>> there is a way when we understand the problem to restart hylafax every
>> received fax??
>>
>>
>> thanks,
>>
>> Fabio
>>

Attachment: signature.asc
Description: OpenPGP digital signature